1# Copyright 2017 The Chromium OS Authors. All rights reserved. 2# Use of this source code is governed by a BSD-style license that can be 3# found in the LICENSE file. 4 5import json 6import logging 7import os 8import socket 9import time 10import urllib2 11import urlparse 12 13from autotest_lib.client.bin import utils as client_utils 14from autotest_lib.client.common_lib import error 15from autotest_lib.client.common_lib import global_config 16from autotest_lib.client.common_lib.cros import dev_server 17from autotest_lib.server import hosts 18 19 20def snippet(text): 21 """Returns the text with start/end snip markers around it. 22 23 @param text: The snippet text. 24 25 @return The text with start/end snip markers around it. 26 """ 27 snip = '---8<---' * 10 28 start = '-- START -' 29 end = '-- END -' 30 return ('%s%s\n%s\n%s%s' % 31 (start, snip[len(start):], text, end, snip[len(end):])) 32 33 34class OmahaDevserverFailedToStart(error.TestError): 35 """Raised when a omaha devserver fails to start.""" 36 37 38class OmahaDevserver(object): 39 """Spawns a test-private devserver instance.""" 40 # How long to wait for a devserver to start. 41 _WAIT_FOR_DEVSERVER_STARTED_SECONDS = 30 42 43 # How long to sleep (seconds) between checks to see if a devserver is up. 44 _WAIT_SLEEP_INTERVAL = 1 45 46 # Max devserver execution time (seconds); used with timeout(1) to ensure we 47 # don't have defunct instances hogging the system. 48 _DEVSERVER_TIMELIMIT_SECONDS = 12 * 60 * 60 49 50 51 def __init__(self, omaha_host, payload_location, critical_update=True, 52 moblab=False): 53 """Starts a private devserver instance, operating at Omaha capacity. 54 55 @param omaha_host: host address where the devserver is spawned. 56 @param payload_location: partial path from static dir to payload. 57 @param critical_update: Whether to set a deadline in responses. 58 @param moblab: True if we are running on moblab. 59 60 """ 61 self._critical_update = critical_update 62 self._omaha_host = omaha_host 63 self._devserver_pid = 0 64 self._devserver_port = 0 # Determined later from devserver portfile. 65 self._payload_location = payload_location 66 67 # Temporary files for various devserver outputs. 68 self._devserver_logfile = None 69 self._devserver_stdoutfile = None 70 self._devserver_portfile = None 71 self._devserver_pidfile = None 72 self._devserver_static_dir = None 73 74 if moblab: 75 self._devserver_dir = global_config.global_config.get_config_value( 76 'CROS', 'devserver_dir') 77 ssh_user = 'moblab' 78 os.environ['CROS_CACHEDIR'] = '/mnt/moblab/cros_cache' 79 else: 80 self._devserver_dir = \ 81 '/home/chromeos-test/chromiumos/src/platform/dev' 82 ssh_user = 'chromeos-test' 83 self._devserver_ssh = hosts.SSHHost(self._omaha_host, 84 user=ssh_user) 85 86 87 def _cleanup_devserver_files(self): 88 """Cleans up the temporary devserver files.""" 89 for filename in (self._devserver_logfile, self._devserver_stdoutfile, 90 self._devserver_portfile, self._devserver_pidfile): 91 if filename: 92 self._devserver_ssh.run('rm -f %s' % filename, 93 ignore_status=True) 94 95 if self._devserver_static_dir: 96 self._devserver_ssh.run('rm -rf %s' % self._devserver_static_dir, 97 ignore_status=True) 98 99 100 def _create_tempfile_on_devserver(self, label, dir=False): 101 """Creates a temporary file/dir on the devserver and returns its path. 102 103 @param label: Identifier for the file context (string, no whitespaces). 104 @param dir: If True, create a directory instead of a file. 105 106 @raises test.TestError: If we failed to invoke mktemp on the server. 107 @raises OmahaDevserverFailedToStart: If tempfile creation failed. 108 """ 109 remote_cmd = 'mktemp --tmpdir devserver-%s.XXXXXX' % label 110 if dir: 111 remote_cmd += ' --directory' 112 113 logging.info(remote_cmd) 114 115 try: 116 result = self._devserver_ssh.run(remote_cmd, ignore_status=True, 117 ssh_failure_retry_ok=True) 118 except error.AutoservRunError as e: 119 self._log_and_raise_remote_ssh_error(e) 120 if result.exit_status != 0: 121 logging.info(result) 122 raise OmahaDevserverFailedToStart( 123 'Could not create a temporary %s file on the devserver, ' 124 'error output: "%s"' % (label, result.stderr)) 125 return result.stdout.strip() 126 127 128 @staticmethod 129 def _log_and_raise_remote_ssh_error(e): 130 """Logs failure to ssh remote, then raises a TestError.""" 131 logging.debug('Failed to ssh into the devserver: %s', e) 132 logging.error('If you are running this locally it means you did not ' 133 'configure ssh correctly.') 134 raise error.TestError('Failed to ssh into the devserver: %s' % e) 135 136 137 def _read_int_from_devserver_file(self, filename): 138 """Reads and returns an integer value from a file on the devserver.""" 139 return int(self._get_devserver_file_content(filename).strip()) 140 141 142 def _wait_for_devserver_to_start(self): 143 """Waits until the devserver starts within the time limit. 144 145 Infers and sets the devserver PID and serving port. 146 147 Raises: 148 OmahaDevserverFailedToStart: If the time limit is reached and we 149 cannot connect to the devserver. 150 """ 151 # Compute the overall timeout. 152 deadline = time.time() + self._WAIT_FOR_DEVSERVER_STARTED_SECONDS 153 154 # First, wait for port file to be filled and determine the server port. 155 logging.warning('Waiting for devserver to start up.') 156 while time.time() < deadline: 157 try: 158 self._devserver_pid = self._read_int_from_devserver_file( 159 self._devserver_pidfile) 160 self._devserver_port = self._read_int_from_devserver_file( 161 self._devserver_portfile) 162 logging.info('Devserver pid is %d, serving on port %d', 163 self._devserver_pid, self._devserver_port) 164 break 165 except Exception: # Couldn't read file or corrupt content. 166 time.sleep(self._WAIT_SLEEP_INTERVAL) 167 else: 168 try: 169 self._devserver_ssh.run_output('uptime', 170 ssh_failure_retry_ok=True) 171 except error.AutoservRunError as e: 172 logging.debug('Failed to run uptime on the devserver: %s', e) 173 raise OmahaDevserverFailedToStart( 174 'The test failed to find the pid/port of the omaha ' 175 'devserver after %d seconds. Check the dumped devserver ' 176 'logs and devserver load for more information.' % 177 self._WAIT_FOR_DEVSERVER_STARTED_SECONDS) 178 179 # Check that the server is reponsding to network requests. 180 logging.warning('Waiting for devserver to accept network requests.') 181 url = 'http://%s' % self.get_netloc() 182 while time.time() < deadline: 183 if dev_server.ImageServer.devserver_healthy(url, timeout_min=0.1): 184 break 185 186 # TODO(milleral): Refactor once crbug.com/221626 is resolved. 187 time.sleep(self._WAIT_SLEEP_INTERVAL) 188 else: 189 raise OmahaDevserverFailedToStart( 190 'The test failed to establish a connection to the omaha ' 191 'devserver it set up on port %d. Check the dumped ' 192 'devserver logs for more information.' % 193 self._devserver_port) 194 195 196 def start_devserver(self): 197 """Starts the devserver and confirms it is up. 198 199 Raises: 200 test.TestError: If we failed to spawn the remote devserver. 201 OmahaDevserverFailedToStart: If the time limit is reached and we 202 cannot connect to the devserver. 203 """ 204 # Allocate temporary files for various server outputs. 205 self._devserver_logfile = self._create_tempfile_on_devserver('log') 206 self._devserver_stdoutfile = self._create_tempfile_on_devserver( 207 'stdout') 208 self._devserver_portfile = self._create_tempfile_on_devserver('port') 209 self._devserver_pidfile = self._create_tempfile_on_devserver('pid') 210 self._devserver_static_dir = self._create_tempfile_on_devserver( 211 'static', dir=True) 212 213 # Invoke the Omaha/devserver on the remote server. Will attempt to kill 214 # it with a SIGTERM after a predetermined timeout has elapsed, followed 215 # by SIGKILL if not dead within 30 seconds from the former signal. 216 cmdlist = [ 217 'timeout', '-s', 'TERM', '-k', '30', 218 str(self._DEVSERVER_TIMELIMIT_SECONDS), 219 '%s/devserver.py' % self._devserver_dir, 220 '--port=0', 221 '--pidfile=%s' % self._devserver_pidfile, 222 '--portfile=%s' % self._devserver_portfile, 223 '--logfile=%s' % self._devserver_logfile, 224 '--host_log', 225 '--static_dir=%s' % self._devserver_static_dir, 226 '--payload=%s' % os.path.join(self._devserver_static_dir, 227 self._payload_location), 228 ] 229 230 if self._critical_update: 231 cmdlist.append('--critical_update') 232 233 remote_cmd = '( %s ) </dev/null >%s 2>&1 &' % ( 234 ' '.join(cmdlist), self._devserver_stdoutfile) 235 236 logging.info('Starting devserver with %r', remote_cmd) 237 try: 238 self._devserver_ssh.run_output(remote_cmd, 239 ssh_failure_retry_ok=True) 240 except error.AutoservRunError as e: 241 self._log_and_raise_remote_ssh_error(e) 242 243 try: 244 self._wait_for_devserver_to_start() 245 except OmahaDevserverFailedToStart: 246 self._kill_remote_process() 247 self._dump_devserver_log() 248 self._cleanup_devserver_files() 249 raise 250 251 252 def _kill_remote_process(self): 253 """Kills the devserver and verifies it's down; clears the remote pid.""" 254 def devserver_down(): 255 """Ensure that the devserver process is down.""" 256 return not self._remote_process_alive() 257 258 if devserver_down(): 259 return 260 261 for signal in 'SIGTERM', 'SIGKILL': 262 remote_cmd = 'kill -s %s %s' % (signal, self._devserver_pid) 263 self._devserver_ssh.run(remote_cmd, ssh_failure_retry_ok=True) 264 try: 265 client_utils.poll_for_condition( 266 devserver_down, sleep_interval=1, desc='devserver down') 267 break 268 except client_utils.TimeoutError: 269 logging.warning('Could not kill devserver with %s.', signal) 270 else: 271 logging.warning('Failed to kill devserver, giving up.') 272 273 self._devserver_pid = None 274 275 276 def _remote_process_alive(self): 277 """Tests whether the remote devserver process is running.""" 278 if not self._devserver_pid: 279 return False 280 remote_cmd = 'test -e /proc/%s' % self._devserver_pid 281 result = self._devserver_ssh.run(remote_cmd, ignore_status=True) 282 return result.exit_status == 0 283 284 285 def get_netloc(self): 286 """Returns the netloc (host:port) of the devserver.""" 287 if not (self._devserver_pid and self._devserver_port): 288 raise error.TestError('No running omaha/devserver') 289 290 return '%s:%s' % (self._omaha_host, self._devserver_port) 291 292 293 def get_update_url(self): 294 """Returns the update_url you can use to update via this server.""" 295 return urlparse.urlunsplit(('http', self.get_netloc(), '/update', 296 '', '')) 297 298 299 def _get_devserver_file_content(self, filename): 300 """Returns the content of a file on the devserver.""" 301 return self._devserver_ssh.run_output('cat %s' % filename, 302 stdout_tee=None, 303 ssh_failure_retry_ok=True) 304 305 306 def _get_devserver_log(self): 307 """Obtain the devserver output.""" 308 return self._get_devserver_file_content(self._devserver_logfile) 309 310 311 def _get_devserver_stdout(self): 312 """Obtain the devserver output in stdout and stderr.""" 313 return self._get_devserver_file_content(self._devserver_stdoutfile) 314 315 316 def get_hostlog(self, ip, wait_for_reboot_events=False): 317 """Get the update events json (aka hostlog). 318 319 @param ip: IP of the DUT to get update info for. 320 @param wait_for_reboot_events: True if we expect the reboot events. 321 322 @return the json dump of the update events for the given IP. 323 """ 324 omaha_hostlog_url = urlparse.urlunsplit( 325 ['http', self.get_netloc(), '/api/hostlog', 326 'ip=' + ip, '']) 327 328 # Wait for a few minutes for the post-reboot update check. 329 timeout = time.time() + 60 * 3 330 while True: 331 try: 332 conn = urllib2.urlopen(omaha_hostlog_url) 333 except urllib2.URLError, e: 334 logging.warning('Failed to read event log url: %s', e) 335 return None 336 except socket.timeout, e: 337 logging.warning('Timed out reading event log url: %s', e) 338 return None 339 340 event_log_resp = conn.read() 341 conn.close() 342 hostlog = json.loads(event_log_resp) 343 logging.debug('hostlog returned: %s', hostlog) 344 if wait_for_reboot_events: 345 if 'event_type' in hostlog[-1] and \ 346 hostlog[-1]['event_type'] == 54: 347 return hostlog 348 else: 349 time.sleep(5) 350 if time.time() > timeout: 351 return None 352 continue 353 else: 354 return hostlog 355 356 357 def _dump_devserver_log(self, logging_level=logging.ERROR): 358 """Dump the devserver log to the autotest log. 359 360 @param logging_level: logging level (from logging) to log the output. 361 """ 362 logging.log(logging_level, "Devserver stdout and stderr:\n" + 363 snippet(self._get_devserver_stdout())) 364 logging.log(logging_level, "Devserver log file:\n" + 365 snippet(self._get_devserver_log())) 366 367 368 def stop_devserver(self): 369 """Kill remote process and wait for it to die, dump its output.""" 370 if not self._devserver_pid: 371 logging.error('No running omaha/devserver.') 372 return 373 374 logging.info('Killing omaha/devserver') 375 self._kill_remote_process() 376 logging.debug('Final devserver log before killing') 377 self._dump_devserver_log(logging.DEBUG) 378 self._cleanup_devserver_files() 379