1# This Source Code Form is subject to the terms of the Mozilla Public 2# License, v. 2.0. If a copy of the MPL was not distributed with this file, 3# You can obtain one at http://mozilla.org/MPL/2.0/. 4from __future__ import absolute_import 5 6import pprint 7import signal 8import six 9import sys 10import time 11import traceback 12import subprocess 13from threading import Event 14 15import mozcrash 16import psutil 17from mozlog import get_proxy_logger 18from mozprocess import ProcessHandler 19from talos.utils import TalosError 20 21LOG = get_proxy_logger() 22 23 24class ProcessContext(object): 25 """ 26 Store useful results of the browser execution. 27 """ 28 29 def __init__(self, is_launcher=False): 30 self.output = None 31 self.process = None 32 self.is_launcher = is_launcher 33 34 @property 35 def pid(self): 36 return self.process and self.process.pid 37 38 def kill_process(self): 39 """ 40 Kill the process, returning the exit code or None if the process 41 is already finished. 42 """ 43 parentProc = self.process 44 # If we're using a launcher process, terminate that instead of us: 45 kids = parentProc and parentProc.is_running() and parentProc.children() 46 if self.is_launcher and kids and len(kids) == 1 and kids[0].is_running(): 47 LOG.debug( 48 ( 49 "Launcher process {} detected. Terminating parent" 50 " process {} instead." 51 ).format(parentProc, kids[0]) 52 ) 53 parentProc = kids[0] 54 55 if parentProc and parentProc.is_running(): 56 LOG.debug("Terminating %s" % parentProc) 57 try: 58 parentProc.terminate() 59 except psutil.NoSuchProcess: 60 procs = parentProc.children() 61 for p in procs: 62 c = ProcessContext() 63 c.process = p 64 c.kill_process() 65 return parentProc.returncode 66 try: 67 return parentProc.wait(3) 68 except psutil.TimeoutExpired: 69 LOG.debug("Killing %s" % parentProc) 70 parentProc.kill() 71 # will raise TimeoutExpired if unable to kill 72 return parentProc.wait(3) 73 74 75class Reader(object): 76 def __init__(self, event): 77 self.output = [] 78 self.got_end_timestamp = False 79 self.got_timeout = False 80 self.timeout_message = "" 81 self.got_error = False 82 self.event = event 83 self.proc = None 84 85 def __call__(self, line): 86 line = six.ensure_str(line) 87 if line.find("__endTimestamp") != -1: 88 self.got_end_timestamp = True 89 self.event.set() 90 elif line == "TART: TIMEOUT": 91 self.got_timeout = True 92 self.timeout_message = "TART" 93 self.event.set() 94 elif line.startswith("TEST-UNEXPECTED-FAIL | "): 95 self.got_error = True 96 self.event.set() 97 98 if not ( 99 line.startswith("JavaScript error:") 100 or line.startswith("JavaScript warning:") 101 ): 102 LOG.process_output(self.proc.pid, line) 103 self.output.append(line) 104 105 106def run_browser( 107 command, 108 minidump_dir, 109 timeout=None, 110 on_started=None, 111 debug=None, 112 debugger=None, 113 debugger_args=None, 114 **kwargs 115): 116 """ 117 Run the browser using the given `command`. 118 119 After the browser prints __endTimestamp, we give it 5 120 seconds to quit and kill it if it's still alive at that point. 121 122 Note that this method ensure that the process is killed at 123 the end. If this is not possible, an exception will be raised. 124 125 :param command: the commad (as a string list) to run the browser 126 :param minidump_dir: a path where to extract minidumps in case the 127 browser hang. This have to be the same value 128 used in `mozcrash.check_for_crashes`. 129 :param timeout: if specified, timeout to wait for the browser before 130 we raise a :class:`TalosError` 131 :param on_started: a callback that can be used to do things just after 132 the browser has been started. The callback must takes 133 an argument, which is the psutil.Process instance 134 :param kwargs: additional keyword arguments for the :class:`ProcessHandler` 135 instance 136 137 Returns a ProcessContext instance, with available output and pid used. 138 """ 139 140 debugger_info = find_debugger_info(debug, debugger, debugger_args) 141 if debugger_info is not None: 142 return run_in_debug_mode( 143 command, debugger_info, on_started=on_started, env=kwargs.get("env") 144 ) 145 146 is_launcher = sys.platform.startswith("win") and "-wait-for-browser" in command 147 context = ProcessContext(is_launcher) 148 first_time = int(time.time()) * 1000 149 wait_for_quit_timeout = 20 150 event = Event() 151 reader = Reader(event) 152 153 LOG.info("Using env: %s" % pprint.pformat(kwargs["env"])) 154 155 kwargs["storeOutput"] = False 156 kwargs["processOutputLine"] = reader 157 kwargs["onFinish"] = event.set 158 proc = ProcessHandler(command, **kwargs) 159 reader.proc = proc 160 proc.run() 161 162 LOG.process_start(proc.pid, " ".join(command)) 163 try: 164 context.process = psutil.Process(proc.pid) 165 if on_started: 166 on_started(context.process) 167 # wait until we saw __endTimestamp in the proc output, 168 # or the browser just terminated - or we have a timeout 169 if not event.wait(timeout): 170 LOG.info("Timeout waiting for test completion; killing browser...") 171 # try to extract the minidump stack if the browser hangs 172 kill_and_get_minidump(context, minidump_dir) 173 raise TalosError("timeout") 174 if reader.got_end_timestamp: 175 for i in six.moves.range(1, wait_for_quit_timeout): 176 if proc.wait(1) is not None: 177 break 178 if proc.poll() is None: 179 LOG.info( 180 "Browser shutdown timed out after {0} seconds, killing" 181 " process.".format(wait_for_quit_timeout) 182 ) 183 kill_and_get_minidump(context, minidump_dir) 184 raise TalosError( 185 "Browser shutdown timed out after {0} seconds, killed" 186 " process.".format(wait_for_quit_timeout) 187 ) 188 elif reader.got_timeout: 189 raise TalosError("TIMEOUT: %s" % reader.timeout_message) 190 elif reader.got_error: 191 raise TalosError("unexpected error") 192 finally: 193 # this also handle KeyboardInterrupt 194 # ensure early the process is really terminated 195 return_code = None 196 try: 197 return_code = context.kill_process() 198 if return_code is None: 199 return_code = proc.wait(1) 200 except Exception: 201 # Maybe killed by kill_and_get_minidump(), maybe ended? 202 LOG.info("Unable to kill process") 203 LOG.info(traceback.format_exc()) 204 205 reader.output.append( 206 "__startBeforeLaunchTimestamp%d__endBeforeLaunchTimestamp" % first_time 207 ) 208 reader.output.append( 209 "__startAfterTerminationTimestamp%d__endAfterTerminationTimestamp" 210 % (int(time.time()) * 1000) 211 ) 212 213 if return_code is not None: 214 LOG.process_exit(proc.pid, return_code) 215 else: 216 LOG.debug("Unable to detect exit code of the process %s." % proc.pid) 217 context.output = reader.output 218 return context 219 220 221def find_debugger_info(debug, debugger, debugger_args): 222 debuggerInfo = None 223 if debug or debugger or debugger_args: 224 import mozdebug 225 226 if not debugger: 227 # No debugger name was provided. Look for the default ones on 228 # current OS. 229 debugger = mozdebug.get_default_debugger_name( 230 mozdebug.DebuggerSearch.KeepLooking 231 ) 232 233 debuggerInfo = None 234 if debugger: 235 debuggerInfo = mozdebug.get_debugger_info(debugger, debugger_args) 236 237 if debuggerInfo is None: 238 raise TalosError("Could not find a suitable debugger in your PATH.") 239 240 return debuggerInfo 241 242 243def run_in_debug_mode(command, debugger_info, on_started=None, env=None): 244 signal.signal(signal.SIGINT, lambda sigid, frame: None) 245 context = ProcessContext() 246 command_under_dbg = [debugger_info.path] + debugger_info.args + command 247 248 ttest_process = subprocess.Popen(command_under_dbg, env=env) 249 250 context.process = psutil.Process(ttest_process.pid) 251 if on_started: 252 on_started(context.process) 253 254 return_code = ttest_process.wait() 255 256 if return_code is not None: 257 LOG.process_exit(ttest_process.pid, return_code) 258 else: 259 LOG.debug("Unable to detect exit code of the process %s." % ttest_process.pid) 260 261 return context 262 263 264def kill_and_get_minidump(context, minidump_dir): 265 proc = context.process 266 if context.is_launcher: 267 kids = context.process.children() 268 if len(kids) == 1: 269 LOG.debug( 270 ( 271 "Launcher process {} detected. Killing parent" 272 " process {} instead." 273 ).format(proc, kids[0]) 274 ) 275 proc = kids[0] 276 LOG.debug("Killing %s and writing a minidump file" % proc) 277 mozcrash.kill_and_get_minidump(proc.pid, minidump_dir) 278