Unreviewed. Update W3C WebDriver imported tests.
[WebKit-https.git] / WebDriverTests / imported / w3c / tools / wptrunner / wptrunner / stability.py
1 import copy
2 import functools
3 import imp
4 import io
5 import os
6 from collections import OrderedDict, defaultdict
7 from datetime import datetime
8
9 from mozlog import reader
10 from mozlog.formatters import JSONFormatter
11 from mozlog.handlers import BaseHandler, StreamHandler, LogLevelFilter
12
13 here = os.path.dirname(__file__)
14 localpaths = imp.load_source("localpaths", os.path.abspath(os.path.join(here, os.pardir, os.pardir, "localpaths.py")))
15 from wpt.markdown import markdown_adjust, table
16
17
18 class LogActionFilter(BaseHandler):
19
20     """Handler that filters out messages not of a given set of actions.
21
22     Subclasses BaseHandler.
23
24     :param inner: Handler to use for messages that pass this filter
25     :param actions: List of actions for which to fire the handler
26     """
27
28     def __init__(self, inner, actions):
29         """Extend BaseHandler and set inner and actions props on self."""
30         BaseHandler.__init__(self, inner)
31         self.inner = inner
32         self.actions = actions
33
34     def __call__(self, item):
35         """Invoke handler if action is in list passed as constructor param."""
36         if item["action"] in self.actions:
37             return self.inner(item)
38
39
40 class LogHandler(reader.LogHandler):
41
42     """Handle updating test and subtest status in log.
43
44     Subclasses reader.LogHandler.
45     """
46     def __init__(self):
47         self.results = OrderedDict()
48
49     def find_or_create_test(self, data):
50         test_name = data["test"]
51         if self.results.get(test_name):
52             return self.results[test_name]
53
54         test = {
55             "subtests": OrderedDict(),
56             "status": defaultdict(int)
57         }
58         self.results[test_name] = test
59         return test
60
61     def find_or_create_subtest(self, data):
62         test = self.find_or_create_test(data)
63         subtest_name = data["subtest"]
64
65         if test["subtests"].get(subtest_name):
66             return test["subtests"][subtest_name]
67
68         subtest = {
69             "status": defaultdict(int),
70             "messages": set()
71         }
72         test["subtests"][subtest_name] = subtest
73
74         return subtest
75
76     def test_status(self, data):
77         subtest = self.find_or_create_subtest(data)
78         subtest["status"][data["status"]] += 1
79         if data.get("message"):
80             subtest["messages"].add(data["message"])
81
82     def test_end(self, data):
83         test = self.find_or_create_test(data)
84         test["status"][data["status"]] += 1
85
86
87 def is_inconsistent(results_dict, iterations):
88     """Return whether or not a single test is inconsistent."""
89     if 'SKIP' in results_dict:
90         return False
91     return len(results_dict) > 1 or sum(results_dict.values()) != iterations
92
93
94 def process_results(log, iterations):
95     """Process test log and return overall results and list of inconsistent tests."""
96     inconsistent = []
97     handler = LogHandler()
98     reader.handle_log(reader.read(log), handler)
99     results = handler.results
100     for test_name, test in results.iteritems():
101         if is_inconsistent(test["status"], iterations):
102             inconsistent.append((test_name, None, test["status"], []))
103         for subtest_name, subtest in test["subtests"].iteritems():
104             if is_inconsistent(subtest["status"], iterations):
105                 inconsistent.append((test_name, subtest_name, subtest["status"], subtest["messages"]))
106     return results, inconsistent
107
108
109 def err_string(results_dict, iterations):
110     """Create and return string with errors from test run."""
111     rv = []
112     total_results = sum(results_dict.values())
113     for key, value in sorted(results_dict.items()):
114         rv.append("%s%s" %
115                   (key, ": %s/%s" % (value, iterations) if value != iterations else ""))
116     if total_results < iterations:
117         rv.append("MISSING: %s/%s" % (iterations - total_results, iterations))
118     rv = ", ".join(rv)
119     if is_inconsistent(results_dict, iterations):
120         rv = "**%s**" % rv
121     return rv
122
123
124 def write_inconsistent(log, inconsistent, iterations):
125     """Output inconsistent tests to logger.error."""
126     log("## Unstable results ##\n")
127     strings = [(
128         "`%s`" % markdown_adjust(test),
129         ("`%s`" % markdown_adjust(subtest)) if subtest else "",
130         err_string(results, iterations),
131         ("`%s`" % markdown_adjust(";".join(messages))) if len(messages) else "")
132         for test, subtest, results, messages in inconsistent]
133     table(["Test", "Subtest", "Results", "Messages"], strings, log)
134
135
136 def write_results(log, results, iterations, pr_number=None, use_details=False):
137     log("## All results ##\n")
138     if use_details:
139         log("<details>\n")
140         log("<summary>%i %s ran</summary>\n\n" % (len(results),
141                                                   "tests" if len(results) > 1
142                                                   else "test"))
143
144     for test_name, test in results.iteritems():
145         baseurl = "http://w3c-test.org/submissions"
146         if "https" in os.path.splitext(test_name)[0].split(".")[1:]:
147             baseurl = "https://w3c-test.org/submissions"
148         title = test_name
149         if use_details:
150             log("<details>\n")
151             if pr_number:
152                 title = "<a href=\"%s/%s%s\">%s</a>" % (baseurl, pr_number, test_name, title)
153             log('<summary>%s</summary>\n\n' % title)
154         else:
155             log("### %s ###" % title)
156         strings = [("", err_string(test["status"], iterations), "")]
157
158         strings.extend(((
159             ("`%s`" % markdown_adjust(subtest_name)) if subtest else "",
160             err_string(subtest["status"], iterations),
161             ("`%s`" % markdown_adjust(';'.join(subtest["messages"]))) if len(subtest["messages"]) else "")
162             for subtest_name, subtest in test["subtests"].items()))
163         table(["Subtest", "Results", "Messages"], strings, log)
164         if use_details:
165             log("</details>\n")
166
167     if use_details:
168         log("</details>\n")
169
170
171 def run_step(logger, iterations, restart_after_iteration, kwargs_extras, **kwargs):
172     import wptrunner
173     kwargs = copy.deepcopy(kwargs)
174
175     if restart_after_iteration:
176         kwargs["repeat"] = iterations
177     else:
178         kwargs["rerun"] = iterations
179
180     kwargs["pause_after_test"] = False
181     kwargs.update(kwargs_extras)
182
183     def wrap_handler(x):
184         x = LogLevelFilter(x, "WARNING")
185         if not kwargs["verify_log_full"]:
186             x = LogActionFilter(x, ["log", "process_output"])
187         return x
188
189     initial_handlers = logger._state.handlers
190     logger._state.handlers = [wrap_handler(handler)
191                               for handler in initial_handlers]
192
193     log = io.BytesIO()
194     # Setup logging for wptrunner that keeps process output and
195     # warning+ level logs only
196     logger.add_handler(StreamHandler(log, JSONFormatter()))
197
198     wptrunner.run_tests(**kwargs)
199
200     logger._state.handlers = initial_handlers
201     logger._state.running_tests = set()
202     logger._state.suite_started = False
203
204     log.seek(0)
205     results, inconsistent = process_results(log, iterations)
206     return results, inconsistent, iterations
207
208
209 def get_steps(logger, repeat_loop, repeat_restart, kwargs_extras):
210     steps = []
211     for kwargs_extra in kwargs_extras:
212         if kwargs_extra:
213             flags_string = " with flags %s" % " ".join(
214                 "%s=%s" % item for item in kwargs_extra.iteritems())
215         else:
216             flags_string = ""
217
218         if repeat_loop:
219             desc = "Running tests in a loop %d times%s" % (repeat_loop,
220                                                            flags_string)
221             steps.append((desc, functools.partial(run_step, logger, repeat_loop, False, kwargs_extra)))
222
223         if repeat_restart:
224             desc = "Running tests in a loop with restarts %s times%s" % (repeat_restart,
225                                                                          flags_string)
226             steps.append((desc, functools.partial(run_step, logger, repeat_restart, True, kwargs_extra)))
227
228     return steps
229
230
231 def write_summary(logger, step_results, final_result):
232     for desc, result in step_results:
233         logger.info('::: %s : %s' % (desc, result))
234     logger.info(':::')
235     if final_result == "PASS":
236         log = logger.info
237     elif final_result == "TIMEOUT":
238         log = logger.warning
239     else:
240         log = logger.error
241     log('::: Test verification %s' % final_result)
242
243     logger.info(':::')
244
245
246 def check_stability(logger, repeat_loop=10, repeat_restart=5, chaos_mode=True, max_time=None,
247                     output_results=True, **kwargs):
248     kwargs_extras = [{}]
249     if chaos_mode and kwargs["product"] == "firefox":
250         kwargs_extras.append({"chaos_mode_flags": 3})
251
252     steps = get_steps(logger, repeat_loop, repeat_restart, kwargs_extras)
253
254     start_time = datetime.now()
255     step_results = []
256
257     for desc, step_func in steps:
258         if max_time and datetime.now() - start_time > max_time:
259             logger.info("::: Test verification is taking too long: Giving up!")
260             logger.info("::: So far, all checks passed, but not all checks were run.")
261             write_summary(logger, step_results, "TIMEOUT")
262             return 2
263
264         logger.info(':::')
265         logger.info('::: Running test verification step "%s"...' % desc)
266         logger.info(':::')
267         results, inconsistent, iterations = step_func(**kwargs)
268         if output_results:
269             write_results(logger.info, results, iterations)
270
271         if inconsistent:
272             step_results.append((desc, "FAIL"))
273             write_inconsistent(logger.info, inconsistent, iterations)
274             write_summary(logger, step_results, "FAIL")
275             return 1
276
277         step_results.append((desc,  "PASS"))
278
279     write_summary(logger, step_results, "PASS")