blob: d16b453b2f88b36e91f153105e474fb894c26341 [file] [log] [blame]
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001#!/usr/bin/python -u
Hung-Te Lin1990b742017-08-09 17:34:57 +08002# Copyright 2012 The Chromium OS Authors. All rights reserved.
Hung-Te Linf2f78f72012-02-08 19:27:11 +08003# Use of this source code is governed by a BSD-style license that can be
4# found in the LICENSE file.
5
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08006"""The main factory flow that runs the factory test and finalizes a device."""
Hung-Te Linf2f78f72012-02-08 19:27:11 +08007
Joel Kitchingb85ed7f2014-10-08 18:24:39 +08008from __future__ import print_function
9
Jon Salz0405ab52012-03-16 15:26:52 +080010import logging
Wei-Han Chenc17b4112016-11-22 14:56:51 +080011from optparse import OptionParser
Jon Salz0405ab52012-03-16 15:26:52 +080012import os
Hung-Te Lina452d4d2017-10-25 17:46:14 +080013import Queue
Jon Salz77c151e2012-08-28 07:20:37 +080014import signal
Jon Salz0405ab52012-03-16 15:26:52 +080015import sys
Jon Salz0405ab52012-03-16 15:26:52 +080016import threading
17import time
18import traceback
Jon Salz258a40c2012-04-19 12:34:01 +080019import uuid
Jon Salzb10cf512012-08-09 17:29:21 +080020from xmlrpclib import Binary
Hung-Te Linf2f78f72012-02-08 19:27:11 +080021
Peter Shihfdf17682017-05-26 11:38:39 +080022import factory_common # pylint: disable=unused-import
Hung-Te Linb6287242016-05-18 14:39:05 +080023from cros.factory.device import device_utils
Vic Yangd80ea752014-09-24 16:07:14 +080024from cros.factory.goofy.goofy_rpc import GoofyRPC
Earl Ouacbe99c2017-02-21 16:04:19 +080025from cros.factory.goofy import goofy_server
Wei-Han Chen1a114682017-10-02 10:33:54 +080026from cros.factory.goofy import hooks
Vic Yangd80ea752014-09-24 16:07:14 +080027from cros.factory.goofy.invocation import TestInvocation
Earl Oua3bca122016-10-21 16:00:30 +080028from cros.factory.goofy.plugins import plugin_controller
Vic Yange2c76a82014-10-30 12:48:19 -070029from cros.factory.goofy import prespawner
Earl Oua3bca122016-10-21 16:00:30 +080030from cros.factory.goofy import test_environment
Wei-Han Chenc17b4112016-11-22 14:56:51 +080031from cros.factory.goofy.test_list_iterator import TestListIterator
Earl Oua3bca122016-10-21 16:00:30 +080032from cros.factory.goofy import updater
Vic Yangd80ea752014-09-24 16:07:14 +080033from cros.factory.goofy.web_socket_manager import WebSocketManager
Wei-Han Chen109d76f2017-08-08 18:50:35 +080034from cros.factory.test import device_data
Hung-Te Linb6287242016-05-18 14:39:05 +080035from cros.factory.test.e2e_test.common import AutomationMode
36from cros.factory.test.e2e_test.common import AutomationModePrompt
37from cros.factory.test.e2e_test.common import ParseAutomationMode
Earl Ouacbe99c2017-02-21 16:04:19 +080038from cros.factory.test.env import goofy_proxy
Hung-Te Linb6287242016-05-18 14:39:05 +080039from cros.factory.test.env import paths
Jon Salz83591782012-06-26 11:09:58 +080040from cros.factory.test.event import Event
Shen-En Shihd7359cc2017-10-03 16:01:47 +080041from cros.factory.test.event import ThreadingEventClient
Jon Salz83591782012-06-26 11:09:58 +080042from cros.factory.test.event import EventServer
Hung-Te Linb6287242016-05-18 14:39:05 +080043from cros.factory.test import event_log
44from cros.factory.test.event_log import EventLog
Hung-Te Linb6287242016-05-18 14:39:05 +080045from cros.factory.test.event_log import GetBootSequence
Hung-Te Lin91492a12014-11-25 18:56:30 +080046from cros.factory.test.event_log_watcher import EventLogWatcher
Peter Shihf65db932017-03-22 17:06:34 +080047from cros.factory.test.i18n import test_ui as i18n_test_ui
Peter Shih80e78b42017-03-10 17:00:56 +080048from cros.factory.test.i18n import translation
Hung-Te Lin3f096842016-01-13 17:37:06 +080049from cros.factory.test.rules import phase
Hung-Te Lind151bf32017-08-30 11:05:47 +080050from cros.factory.test import server_proxy
Hung-Te Linda8eb992017-09-28 03:27:12 +080051from cros.factory.test import session
Earl Oua3bca122016-10-21 16:00:30 +080052from cros.factory.test import state
Wei-Han Chen3b030492017-10-12 11:43:27 +080053from cros.factory.test.state import TestState
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +080054from cros.factory.test.test_lists import manager
Wei-Han Chen03113912017-09-29 15:58:25 +080055from cros.factory.test.test_lists import test_object
chuntseneb33f9d2017-05-12 13:38:17 +080056from cros.factory.testlog import testlog
Hung-Te Linb6287242016-05-18 14:39:05 +080057from cros.factory.tools.key_filter import KeyFilter
Wei-Han Chen78f35f62017-03-06 20:11:20 +080058from cros.factory.utils import config_utils
Hung-Te Linf707b242016-01-08 23:11:42 +080059from cros.factory.utils import debug_utils
Jon Salz2af235d2013-06-24 14:47:21 +080060from cros.factory.utils import file_utils
Hung-Te Lin8fc0d652017-09-21 13:05:44 +080061from cros.factory.utils import log_utils
Joel Kitchingb85ed7f2014-10-08 18:24:39 +080062from cros.factory.utils import net_utils
Hung-Te Lin4e6357c2016-01-08 14:32:00 +080063from cros.factory.utils import sys_utils
Hung-Te Linf707b242016-01-08 23:11:42 +080064from cros.factory.utils import type_utils
Hung-Te Linf2f78f72012-02-08 19:27:11 +080065
Earl Ou6de96c02017-05-19 18:51:28 +080066from cros.factory.external import syslog
67
Hung-Te Linf2f78f72012-02-08 19:27:11 +080068
Hung-Te Linf2f78f72012-02-08 19:27:11 +080069HWID_CFG_PATH = '/usr/local/share/chromeos-hwid/cfg'
Peter Shihb4e49352017-05-25 17:35:11 +080070CACHES_DIR = os.path.join(paths.DATA_STATE_DIR, 'caches')
Hung-Te Linf2f78f72012-02-08 19:27:11 +080071
Jon Salz5c344f62012-07-13 14:31:16 +080072# Value for tests_after_shutdown that forces auto-run (e.g., after
73# a factory update, when the available set of tests might change).
74FORCE_AUTO_RUN = 'force_auto_run'
75
Wei-Han Chenc17b4112016-11-22 14:56:51 +080076# Key to load the test list iterator after shutdown test
77TESTS_AFTER_SHUTDOWN = 'tests_after_shutdown'
78
Hung-Te Linf707b242016-01-08 23:11:42 +080079Status = type_utils.Enum(['UNINITIALIZED', 'INITIALIZING', 'RUNNING',
Wei-Han Chen2ebb92d2016-01-12 14:51:41 +080080 'TERMINATING', 'TERMINATED'])
Jon Salzd7550792013-07-12 05:49:27 +080081
Hung-Te Lina452d4d2017-10-25 17:46:14 +080082RUN_QUEUE_TIMEOUT_SECS = 10
83
84class Goofy(object):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +080085 """The main factory flow.
Jon Salz0697cbf2012-07-04 15:14:04 +080086
87 Note that all methods in this class must be invoked from the main
88 (event) thread. Other threads, such as callbacks and TestInvocation
89 methods, should instead post events on the run queue.
90
91 TODO: Unit tests. (chrome-os-partner:7409)
92
93 Properties:
Hung-Te Lina452d4d2017-10-25 17:46:14 +080094 run_queue: A queue of callbacks to invoke from the main thread.
95 exceptions: List of exceptions encountered in invocation threads.
96 last_idle: The most recent time of invoking the idle queue handler, or none.
Jon Salz0697cbf2012-07-04 15:14:04 +080097 uuid: A unique UUID for this invocation of Goofy.
98 state_instance: An instance of FactoryState.
99 state_server: The FactoryState XML/RPC server.
100 state_server_thread: A thread running state_server.
101 event_server: The EventServer socket server.
102 event_server_thread: A thread running event_server.
103 event_client: A client to the event server.
Earl Oua3bca122016-10-21 16:00:30 +0800104 plugin_controller: The PluginController object.
Jon Salz0697cbf2012-07-04 15:14:04 +0800105 invocations: A map from FactoryTest objects to the corresponding
106 TestInvocations objects representing active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +0800107 options: Command-line options.
108 args: Command-line args.
109 test_list: The test list.
Jon Salz128b0932013-07-03 16:55:26 +0800110 test_lists: All new-style test lists.
Ricky Liang4bff3e32014-02-20 18:46:11 +0800111 run_id: The identifier for latest test run.
112 scheduled_run_tests: The list of tests scheduled for latest test run.
Jon Salz0697cbf2012-07-04 15:14:04 +0800113 event_handlers: Map of Event.Type to the method used to handle that
114 event. If the method has an 'event' argument, the event is passed
115 to the handler.
Jon Salz416f9cc2013-05-10 18:32:50 +0800116 hooks: A Hooks object containing hooks for various Goofy actions.
Jon Salzd7550792013-07-12 05:49:27 +0800117 status: The current Goofy status (a member of the Status enum).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800118 """
Ricky Liang45c73e72015-01-15 15:00:30 +0800119
Jon Salz0697cbf2012-07-04 15:14:04 +0800120 def __init__(self):
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800121 self.run_queue = Queue.Queue()
122 self.exceptions = []
123 self.last_idle = None
124
Jon Salz0697cbf2012-07-04 15:14:04 +0800125 self.uuid = str(uuid.uuid4())
126 self.state_instance = None
Earl Ouacbe99c2017-02-21 16:04:19 +0800127 self.goofy_server = None
128 self.goofy_server_thread = None
Jon Salz16d10542012-07-23 12:18:45 +0800129 self.goofy_rpc = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800130 self.event_server = None
131 self.event_server_thread = None
132 self.event_client = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800133 self.log_watcher = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800134 self.event_log = None
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800135 self.testlog = None
Earl Oua3bca122016-10-21 16:00:30 +0800136 self.plugin_controller = None
Vic Yange2c76a82014-10-30 12:48:19 -0700137 self.pytest_prespawner = None
Vic Yanga3cecf82014-12-26 00:44:21 -0800138 self._ui_initialized = False
Jon Salz0697cbf2012-07-04 15:14:04 +0800139 self.invocations = {}
Jon Salz0697cbf2012-07-04 15:14:04 +0800140 self.chrome = None
Jon Salz416f9cc2013-05-10 18:32:50 +0800141 self.hooks = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800142
143 self.options = None
144 self.args = None
145 self.test_list = None
Jon Salz128b0932013-07-03 16:55:26 +0800146 self.test_lists = None
Ricky Liang4bff3e32014-02-20 18:46:11 +0800147 self.run_id = None
148 self.scheduled_run_tests = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800149 self.env = None
Jon Salzb22d1172012-08-06 10:38:57 +0800150 self.last_idle = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800151 self.last_shutdown_time = None
cychiang21886742012-07-05 15:16:32 +0800152 self.last_update_check = None
Cheng-Yi Chiang194d3c02015-03-16 14:37:15 +0800153 self._suppress_periodic_update_messages = False
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +0800154 self._suppress_event_log_error_messages = False
Earl Ouab979142016-10-25 16:48:06 +0800155 self.exclusive_resources = set()
Dean Liao592e4d52013-01-10 20:06:39 +0800156 self.key_filter = None
Jon Salzd7550792013-07-12 05:49:27 +0800157 self.status = Status.UNINITIALIZED
Ricky Liang36512a32014-07-25 11:47:04 +0800158 self.ready_for_ui_connection = False
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800159 self.is_restart_requested = False
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800160 self.test_list_iterator = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800161
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +0800162 self.test_list_manager = manager.Manager()
163
Hung-Te Lin6a72c642015-12-13 22:09:09 +0800164 # TODO(hungte) Support controlling remote DUT.
Hung-Te Linb6287242016-05-18 14:39:05 +0800165 self.dut = device_utils.CreateDUTInterface()
Hung-Te Lin6a72c642015-12-13 22:09:09 +0800166
Jon Salz85a39882012-07-05 16:45:04 +0800167 def test_or_root(event, parent_or_group=True):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800168 """Returns the test affected by a particular event.
Jon Salz85a39882012-07-05 16:45:04 +0800169
170 Args:
171 event: The event containing an optional 'path' attribute.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800172 parent_or_group: If True, returns the top-level parent for a test (the
Jon Salz85a39882012-07-05 16:45:04 +0800173 root node of the tests that need to be run together if the given test
174 path is to be run).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800175 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800176 try:
177 path = event.path
178 except AttributeError:
179 path = None
180
181 if path:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800182 test = self.test_list.LookupPath(path)
Jon Salz85a39882012-07-05 16:45:04 +0800183 if parent_or_group:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800184 test = test.GetTopLevelParentOrGroup()
Jon Salz85a39882012-07-05 16:45:04 +0800185 return test
Jon Salz0697cbf2012-07-04 15:14:04 +0800186 else:
Peter Shih999faf72017-07-07 11:32:42 +0800187 return self.test_list.ToFactoryTestList()
Jon Salz0697cbf2012-07-04 15:14:04 +0800188
189 self.event_handlers = {
Ricky Liang45c73e72015-01-15 15:00:30 +0800190 Event.Type.RESTART_TESTS:
191 lambda event: self.restart_tests(root=test_or_root(event)),
192 Event.Type.AUTO_RUN:
193 lambda event: self.auto_run(root=test_or_root(event)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800194 Event.Type.RUN_TESTS_WITH_STATUS:
195 lambda event: self.run_tests_with_status(
196 event.status,
197 root=test_or_root(event)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800198 Event.Type.UPDATE_SYSTEM_INFO:
199 lambda event: self.update_system_info(),
200 Event.Type.STOP:
201 lambda event: self.stop(root=test_or_root(event, False),
202 fail=getattr(event, 'fail', False),
203 reason=getattr(event, 'reason', None)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800204 Event.Type.CLEAR_STATE:
205 lambda event: self.clear_state(
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800206 self.test_list.LookupPath(event.path)),
Wei-Ning Huang38b75f02015-02-25 18:25:14 +0800207 Event.Type.KEY_FILTER_MODE: self.handle_key_filter_mode,
Jon Salz0697cbf2012-07-04 15:14:04 +0800208 }
209
Jon Salz0697cbf2012-07-04 15:14:04 +0800210 self.web_socket_manager = None
211
212 def destroy(self):
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800213 """Performs any shutdown tasks."""
chuntsen9d675c62017-06-20 14:35:30 +0800214 # To avoid race condition when running shutdown test.
215 for test, invoc in self.invocations.iteritems():
216 logging.info('Waiting for %s to complete...', test)
217 invoc.thread.join(3) # Timeout in 3 seconds.
218
Jon Salzd7550792013-07-12 05:49:27 +0800219 self.status = Status.TERMINATING
Jon Salz0697cbf2012-07-04 15:14:04 +0800220 if self.chrome:
221 self.chrome.kill()
222 self.chrome = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800223 if self.web_socket_manager:
224 logging.info('Stopping web sockets')
225 self.web_socket_manager.close()
226 self.web_socket_manager = None
Earl Ouacbe99c2017-02-21 16:04:19 +0800227 if self.goofy_server_thread:
228 logging.info('Stopping goofy server')
Peter Shih0a6ae8d2017-10-23 17:59:42 +0800229 net_utils.ShutdownTCPServer(self.goofy_server)
Earl Ouacbe99c2017-02-21 16:04:19 +0800230 self.goofy_server_thread.join()
231 self.goofy_server.server_close()
232 self.goofy_server_thread = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800233 if self.state_instance:
234 self.state_instance.close()
235 if self.event_server_thread:
236 logging.info('Stopping event server')
Peter Shihce9490e2017-05-11 14:32:12 +0800237 net_utils.ShutdownTCPServer(self.event_server)
Jon Salz0697cbf2012-07-04 15:14:04 +0800238 self.event_server_thread.join()
239 self.event_server.server_close()
240 self.event_server_thread = None
241 if self.log_watcher:
242 if self.log_watcher.IsThreadStarted():
243 self.log_watcher.StopWatchThread()
244 self.log_watcher = None
Vic Yange2c76a82014-10-30 12:48:19 -0700245 if self.pytest_prespawner:
246 logging.info('Stopping pytest prespawner')
247 self.pytest_prespawner.stop()
248 self.pytest_prespawner = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800249 if self.event_client:
250 logging.info('Closing event client')
251 self.event_client.close()
252 self.event_client = None
253 if self.event_log:
254 self.event_log.Close()
255 self.event_log = None
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800256 if self.testlog:
257 self.testlog.Close()
258 self.testlog = None
Dean Liao592e4d52013-01-10 20:06:39 +0800259 if self.key_filter:
260 self.key_filter.Stop()
Earl Oua3bca122016-10-21 16:00:30 +0800261 if self.plugin_controller:
262 self.plugin_controller.StopAndDestroyAllPlugins()
263 self.plugin_controller = None
Dean Liao592e4d52013-01-10 20:06:39 +0800264
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800265 self.check_exceptions()
Jon Salz0697cbf2012-07-04 15:14:04 +0800266 logging.info('Done destroying Goofy')
Jon Salzd7550792013-07-12 05:49:27 +0800267 self.status = Status.TERMINATED
Jon Salz0697cbf2012-07-04 15:14:04 +0800268
Earl Ouacbe99c2017-02-21 16:04:19 +0800269 def start_goofy_server(self):
Hung-Te Lin6bfd1de2017-11-10 16:21:33 +0800270 logging.info('Starting goofy server')
Earl Ouacbe99c2017-02-21 16:04:19 +0800271 self.goofy_server = goofy_server.GoofyServer(
Shen-En Shihd5b96bf2017-08-09 17:47:21 +0800272 (goofy_proxy.DEFAULT_GOOFY_BIND, goofy_proxy.DEFAULT_GOOFY_PORT))
Earl Ouacbe99c2017-02-21 16:04:19 +0800273 self.goofy_server_thread = threading.Thread(
274 target=self.goofy_server.serve_forever,
275 name='GoofyServer')
276 self.goofy_server_thread.start()
277
Peter Shihbb771342017-10-19 16:42:28 +0800278 def init_static_files(self):
Peter Shih7cc81b12017-08-24 13:04:46 +0800279 static_path = os.path.join(paths.FACTORY_PYTHON_PACKAGE_DIR, 'goofy/static')
Earl Ouacbe99c2017-02-21 16:04:19 +0800280 # Setup static file path
Peter Shih7cc81b12017-08-24 13:04:46 +0800281 self.goofy_server.RegisterPath('/', static_path)
Earl Ouacbe99c2017-02-21 16:04:19 +0800282
283 def init_state_instance(self):
Jon Salz2af235d2013-06-24 14:47:21 +0800284 # Before starting state server, remount stateful partitions with
285 # no commit flag. The default commit time (commit=600) makes corruption
286 # too likely.
Hung-Te Lin1968d9c2016-01-08 22:55:46 +0800287 sys_utils.ResetCommitTime()
Earl Ouacbe99c2017-02-21 16:04:19 +0800288 self.state_instance = state.FactoryState()
289 self.goofy_server.AddRPCInstance(goofy_proxy.STATE_URL, self.state_instance)
Jon Salz2af235d2013-06-24 14:47:21 +0800290
Earl Ouacbe99c2017-02-21 16:04:19 +0800291 # Setup Goofy RPC.
292 # TODO(shunhsingou): separate goofy_rpc and state server instead of
293 # injecting goofy_rpc functions into state.
Jon Salz16d10542012-07-23 12:18:45 +0800294 self.goofy_rpc = GoofyRPC(self)
295 self.goofy_rpc.RegisterMethods(self.state_instance)
Jon Salz0697cbf2012-07-04 15:14:04 +0800296
Peter Shih80e78b42017-03-10 17:00:56 +0800297 def init_i18n(self):
298 js_data = 'var goofy_i18n_data = %s;' % translation.GetAllI18nDataJS()
Peter Shihce03c2e2017-03-21 17:36:10 +0800299 self.goofy_server.RegisterData('/js/goofy-translations.js',
300 'application/javascript', js_data)
Peter Shihf65db932017-03-22 17:06:34 +0800301 self.goofy_server.RegisterData('/css/i18n.css',
302 'text/css', i18n_test_ui.GetStyleSheet())
Peter Shih80e78b42017-03-10 17:00:56 +0800303
Jon Salz0697cbf2012-07-04 15:14:04 +0800304 def start_event_server(self):
305 self.event_server = EventServer()
306 logging.info('Starting factory event server')
307 self.event_server_thread = threading.Thread(
Ricky Liang45c73e72015-01-15 15:00:30 +0800308 target=self.event_server.serve_forever,
Peter Shihfdf17682017-05-26 11:38:39 +0800309 name='EventServer')
Jon Salz0697cbf2012-07-04 15:14:04 +0800310 self.event_server_thread.start()
311
Shen-En Shihd7359cc2017-10-03 16:01:47 +0800312 self.event_client = ThreadingEventClient(
Shen-En Shihba564cb2017-10-05 11:54:16 +0800313 callback=lambda event: self.run_queue.put(
314 lambda: self.handle_event(event)))
Jon Salz0697cbf2012-07-04 15:14:04 +0800315
316 self.web_socket_manager = WebSocketManager(self.uuid)
Earl Ouacbe99c2017-02-21 16:04:19 +0800317 self.goofy_server.AddHTTPGetHandler(
318 '/event', self.web_socket_manager.handle_web_socket)
Jon Salz0697cbf2012-07-04 15:14:04 +0800319
Ricky Liang48e47f92014-02-26 19:31:51 +0800320 def shutdown(self, operation):
321 """Starts shutdown procedure.
322
323 Args:
Vic (Chun-Ju) Yang05b0d952014-04-28 17:39:09 +0800324 operation: The shutdown operation (reboot, full_reboot, or halt).
Ricky Liang48e47f92014-02-26 19:31:51 +0800325 """
326 active_tests = []
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800327 for test in self.test_list.Walk():
328 if not test.IsLeaf():
Ricky Liang48e47f92014-02-26 19:31:51 +0800329 continue
330
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800331 test_state = test.GetState()
Ricky Liang48e47f92014-02-26 19:31:51 +0800332 if test_state.status == TestState.ACTIVE:
333 active_tests.append(test)
334
Ricky Liang48e47f92014-02-26 19:31:51 +0800335 if not (len(active_tests) == 1 and
Wei-Han Chen03113912017-09-29 15:58:25 +0800336 isinstance(active_tests[0], test_object.ShutdownStep)):
Ricky Liang48e47f92014-02-26 19:31:51 +0800337 logging.error(
338 'Calling Goofy shutdown outside of the shutdown factory test')
339 return
340
341 logging.info('Start Goofy shutdown (%s)', operation)
342 # Save pending test list in the state server
343 self.state_instance.set_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800344 TESTS_AFTER_SHUTDOWN, self.test_list_iterator)
Ricky Liang48e47f92014-02-26 19:31:51 +0800345 # Save shutdown time
346 self.state_instance.set_shared_data('shutdown_time', time.time())
347
348 with self.env.lock:
349 self.event_log.Log('shutdown', operation=operation)
350 shutdown_result = self.env.shutdown(operation)
351 if shutdown_result:
352 # That's all, folks!
Peter Ammon1e1ec572014-06-26 17:56:32 -0700353 self.run_enqueue(None)
Ricky Liang48e47f92014-02-26 19:31:51 +0800354 else:
355 # Just pass (e.g., in the chroot).
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800356 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, None)
Ricky Liang48e47f92014-02-26 19:31:51 +0800357 # Send event with no fields to indicate that there is no
358 # longer a pending shutdown.
359 self.event_client.post_event(Event(Event.Type.PENDING_SHUTDOWN))
360
361 def handle_shutdown_complete(self, test):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800362 """Handles the case where a shutdown was detected during a shutdown step.
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800363
Ricky Liang6fe218c2013-12-27 15:17:17 +0800364 Args:
365 test: The ShutdownStep.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800366 """
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800367 test_state = test.UpdateState(increment_shutdown_count=1)
Jon Salz0697cbf2012-07-04 15:14:04 +0800368 logging.info('Detected shutdown (%d of %d)',
Ricky Liang48e47f92014-02-26 19:31:51 +0800369 test_state.shutdown_count, test.iterations)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800370
Ricky Liang48e47f92014-02-26 19:31:51 +0800371 tests_after_shutdown = self.state_instance.get_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800372 TESTS_AFTER_SHUTDOWN, optional=True)
373
374 # Make this shutdown test the next test to run. This is to continue on
375 # post-shutdown verification in the shutdown step.
Ricky Liang48e47f92014-02-26 19:31:51 +0800376 if not tests_after_shutdown:
Wei-Han Chen29663c12017-06-27 10:28:54 +0800377 goofy_error = 'TESTS_AFTER_SHTUDOWN is not set'
Ricky Liang48e47f92014-02-26 19:31:51 +0800378 self.state_instance.set_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800379 TESTS_AFTER_SHUTDOWN, TestListIterator(test))
380 else:
Wei-Han Chen29663c12017-06-27 10:28:54 +0800381 goofy_error = tests_after_shutdown.RestartLastTest()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800382 self.state_instance.set_shared_data(
383 TESTS_AFTER_SHUTDOWN, tests_after_shutdown)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800384
Ricky Liang48e47f92014-02-26 19:31:51 +0800385 # Set 'post_shutdown' to inform shutdown test that a shutdown just occurred.
Ricky Liangb7eb8772014-09-15 18:05:22 +0800386 self.state_instance.set_shared_data(
Wei-Han Chen29663c12017-06-27 10:28:54 +0800387 state.KEY_POST_SHUTDOWN % test.path,
388 {'invocation': self.state_instance.get_test_state(test.path).invocation,
389 'goofy_error': goofy_error})
Jon Salz258a40c2012-04-19 12:34:01 +0800390
Jon Salz0697cbf2012-07-04 15:14:04 +0800391 def init_states(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800392 """Initializes all states on startup."""
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800393 for test in self.test_list.GetAllTests():
Jon Salz0697cbf2012-07-04 15:14:04 +0800394 # Make sure the state server knows about all the tests,
395 # defaulting to an untested state.
Peter Shih6e578272017-09-12 17:41:43 +0800396 test.UpdateState(update_parent=False)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800397
Earl Ouf76e55c2017-03-07 11:48:34 +0800398 is_unexpected_shutdown = False
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800399
Jon Salz0697cbf2012-07-04 15:14:04 +0800400 # Any 'active' tests should be marked as failed now.
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800401 for test in self.test_list.Walk():
402 if not test.IsLeaf():
Jon Salza6711d72012-07-18 14:33:03 +0800403 # Don't bother with parents; they will be updated when their
404 # children are updated.
405 continue
406
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800407 test_state = test.GetState()
Jon Salz0697cbf2012-07-04 15:14:04 +0800408 if test_state.status != TestState.ACTIVE:
409 continue
Wei-Han Chen03113912017-09-29 15:58:25 +0800410 if isinstance(test, test_object.ShutdownStep):
Jon Salz0697cbf2012-07-04 15:14:04 +0800411 # Shutdown while the test was active - that's good.
Ricky Liang48e47f92014-02-26 19:31:51 +0800412 self.handle_shutdown_complete(test)
Shen-En Shihef6c5ae2017-12-21 14:26:47 +0800413 elif test.allow_reboot:
414 is_unexpected_shutdown = True
415 test.UpdateState(status=TestState.UNTESTED)
416 # For "allow_reboot" tests (such as "Start"), don't cancel
417 # pending tests, since reboot is expected.
418 session.console.info('Unexpected shutdown while test %s was running. '
419 'The test is marked as allow_reboot, continuing '
420 'on pending tests.',
421 test.path)
Jon Salz0697cbf2012-07-04 15:14:04 +0800422 else:
Earl Ouf76e55c2017-03-07 11:48:34 +0800423 is_unexpected_shutdown = True
Jon Salz0697cbf2012-07-04 15:14:04 +0800424 error_msg = 'Unexpected shutdown while test was running'
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800425 # TODO(itspeter): Add testlog to collect expired session infos.
Jon Salz0697cbf2012-07-04 15:14:04 +0800426 self.event_log.Log('end_test',
Ricky Liang45c73e72015-01-15 15:00:30 +0800427 path=test.path,
428 status=TestState.FAILED,
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800429 invocation=test.GetState().invocation,
Earl Ouf76e55c2017-03-07 11:48:34 +0800430 error_msg=error_msg)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800431 test.UpdateState(
Ricky Liang45c73e72015-01-15 15:00:30 +0800432 status=TestState.FAILED,
433 error_msg=error_msg)
Chun-Ta Lin87c2dac2015-05-02 01:35:01 -0700434 # Trigger the OnTestFailure callback.
Claire Changd1961a22015-08-05 16:15:55 +0800435 self.run_queue.put(lambda: self.test_fail(test))
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800436
Shen-En Shihef6c5ae2017-12-21 14:26:47 +0800437 session.console.info('Unexpected shutdown while test %s '
438 'running; cancelling any pending tests',
439 test.path)
440 # cancel pending tests by replace the iterator with an empty one
441 self.state_instance.set_shared_data(
442 TESTS_AFTER_SHUTDOWN,
443 TestListIterator(None))
Jon Salz008f4ea2012-08-28 05:39:45 +0800444
Earl Ouf76e55c2017-03-07 11:48:34 +0800445 if is_unexpected_shutdown:
446 logging.warning("Unexpected shutdown.")
Wei-Han Chen8d7fbc42017-10-18 19:20:47 +0800447 self.hooks.OnUnexpectedReboot(self)
Earl Ouf76e55c2017-03-07 11:48:34 +0800448
Wei-Han Chen109d76f2017-08-08 18:50:35 +0800449 if self.test_list.options.read_device_data_from_vpd_on_init:
450 vpd_data = {}
451 for section in [device_data.NAME_RO, device_data.NAME_RW]:
452 try:
453 vpd_data[section] = self.dut.vpd.boot.GetPartition(section).GetAll()
454 except Exception:
455 logging.exception('Failed to read %s_VPD, ignored...',
456 section.upper())
457 # using None for key_map will use default key_map
458 device_data.UpdateDeviceDataFromVPD(None, vpd_data)
459
Wei-Han Chen212d2af2017-08-03 18:12:23 +0800460 # state_instance is initialized, we can mark skipped and waived tests now.
461 self.test_list.SetSkippedAndWaivedTests()
462
Jon Salz0697cbf2012-07-04 15:14:04 +0800463 def handle_event(self, event):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800464 """Handles an event from the event server."""
Jon Salz0697cbf2012-07-04 15:14:04 +0800465 handler = self.event_handlers.get(event.type)
466 if handler:
467 handler(event)
468 else:
469 # We don't register handlers for all event types - just ignore
470 # this event.
471 logging.debug('Unbound event type %s', event.type)
Jon Salz4f6c7172012-06-11 20:45:36 +0800472
Vic Yangaabf9fd2013-04-09 18:56:13 +0800473 def check_critical_factory_note(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800474 """Returns True if the last factory note is critical."""
Vic Yangaabf9fd2013-04-09 18:56:13 +0800475 notes = self.state_instance.get_shared_data('factory_note', True)
476 return notes and notes[-1]['level'] == 'CRITICAL'
477
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800478 def schedule_restart(self):
479 """Schedules a restart event when any invocation is completed."""
480 self.is_restart_requested = True
481
482 def invocation_completion(self):
483 """Callback when an invocation is completed."""
484 if self.is_restart_requested:
485 logging.info('Restart by scheduled event.')
486 self.is_restart_requested = False
487 self.restart_tests()
488 else:
489 self.run_next_test()
490
Jon Salz0697cbf2012-07-04 15:14:04 +0800491 def run_next_test(self):
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800492 """Runs the next eligible test.
henryhsu4cc6b022014-04-22 17:12:42 +0800493
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800494 self.test_list_iterator (a TestListIterator object) will determine which
495 test should be run.
henryhsu4cc6b022014-04-22 17:12:42 +0800496 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800497 self.reap_completed_tests()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800498
499 if self.invocations:
500 # there are tests still running, we cannot start new tests
Vic Yangaabf9fd2013-04-09 18:56:13 +0800501 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800502
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800503 if self.check_critical_factory_note():
504 logging.info('has critical factory note, stop running')
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800505 self.test_list_iterator.Stop()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800506 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800507
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800508 while True:
509 try:
510 path = self.test_list_iterator.next()
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800511 test = self.test_list.LookupPath(path)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800512 except StopIteration:
513 logging.info('no next test, stop running')
Jon Salz0697cbf2012-07-04 15:14:04 +0800514 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800515
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800516 # check if we have run all required tests
Jon Salz304a75d2012-07-06 11:14:15 +0800517 untested = set()
Jon Salza1412922012-07-23 16:04:17 +0800518 for requirement in test.require_run:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800519 for i in requirement.test.Walk():
Jon Salza1412922012-07-23 16:04:17 +0800520 if i == test:
Jon Salz304a75d2012-07-06 11:14:15 +0800521 # We've hit this test itself; stop checking
522 break
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800523 if ((i.GetState().status == TestState.UNTESTED) or
Wei-Han Chen3a160172017-07-11 17:31:28 +0800524 (requirement.passed and
525 i.GetState().status not in [TestState.SKIPPED,
526 TestState.PASSED])):
Jon Salz304a75d2012-07-06 11:14:15 +0800527 # Found an untested test; move on to the next
528 # element in require_run.
Jon Salza1412922012-07-23 16:04:17 +0800529 untested.add(i)
Jon Salz304a75d2012-07-06 11:14:15 +0800530 break
531
532 if untested:
533 untested_paths = ', '.join(sorted([x.path for x in untested]))
534 if self.state_instance.get_shared_data('engineering_mode',
535 optional=True):
536 # In engineering mode, we'll let it go.
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800537 session.console.warn('In engineering mode; running '
Jon Salz304a75d2012-07-06 11:14:15 +0800538 '%s even though required tests '
539 '[%s] have not completed',
540 test.path, untested_paths)
541 else:
542 # Not in engineering mode; mark it failed.
543 error_msg = ('Required tests [%s] have not been run yet'
544 % untested_paths)
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800545 session.console.error('Not running %s: %s',
Jon Salz304a75d2012-07-06 11:14:15 +0800546 test.path, error_msg)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800547 test.UpdateState(status=TestState.FAILED,
548 error_msg=error_msg)
Jon Salz304a75d2012-07-06 11:14:15 +0800549 continue
550
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800551 # okay, let's run the test
Wei-Han Chen03113912017-09-29 15:58:25 +0800552 if (isinstance(test, test_object.ShutdownStep) and
Ricky Liangb7eb8772014-09-15 18:05:22 +0800553 self.state_instance.get_shared_data(
Wei-Han Chen29663c12017-06-27 10:28:54 +0800554 state.KEY_POST_SHUTDOWN % test.path, optional=True)):
Ricky Liang48e47f92014-02-26 19:31:51 +0800555 # Invoking post shutdown method of shutdown test. We should retain the
556 # iterations_left and retries_left of the original test state.
557 test_state = self.state_instance.get_test_state(test.path)
558 self._run_test(test, test_state.iterations_left,
559 test_state.retries_left)
560 else:
561 # Starts a new test run; reset iterations and retries.
562 self._run_test(test, test.iterations, test.retries)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800563 return # to leave while
Jon Salz1acc8742012-07-17 17:45:55 +0800564
Peter Shih13d2ced2017-09-25 16:25:09 +0800565 def _run_test(self, test, iterations_left=None, retries_left=None,
566 set_layout=True):
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800567 """Invokes the test.
568
569 The argument `test` should be either a leaf test (no subtests) or a parallel
570 test (all subtests should be run in parallel).
571 """
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800572 if not self._ui_initialized and not test.IsNoHost():
Vic Yanga3cecf82014-12-26 00:44:21 -0800573 self.init_ui()
Jon Salz1acc8742012-07-17 17:45:55 +0800574
Peter Shih13d2ced2017-09-25 16:25:09 +0800575 if set_layout:
576 self.event_client.post_event(
577 Event(
578 Event.Type.SET_TEST_UI_LAYOUT,
579 layout_type=test.layout_type,
580 layout_options=test.layout_options))
581
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800582 if test.IsLeaf():
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800583 invoc = TestInvocation(
584 self, test, on_completion=self.invocation_completion,
585 on_test_failure=lambda: self.test_fail(test))
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800586 new_state = test.UpdateState(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800587 status=TestState.ACTIVE, increment_count=1, error_msg='',
588 invocation=invoc.uuid, iterations_left=iterations_left,
Peter Shihf5c048d2017-09-01 17:57:51 +0800589 retries_left=retries_left)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800590 invoc.count = new_state.count
591 self.invocations[test] = invoc
Peter Shihb2ecd552017-08-24 17:48:58 +0800592 # Send a INIT_TEST_UI event here, so the test UI are initialized in
593 # order, and the tab order would be same as test list order when there
594 # are parallel tests with UI.
595 self.event_client.post_event(
596 Event(
597 Event.Type.INIT_TEST_UI,
Peter Shihb2ecd552017-08-24 17:48:58 +0800598 test=test.path,
599 invocation=invoc.uuid))
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800600 self.check_plugins()
601 invoc.start()
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800602 elif test.parallel:
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800603 for subtest in test.subtests:
604 # TODO(stimim): what if the subtests *must* be run in parallel?
605 # for example, stressapptest and countdown test.
606
607 # Make sure we don't need to skip it:
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800608 if not self.test_list_iterator.CheckSkip(subtest):
Peter Shih13d2ced2017-09-25 16:25:09 +0800609 self._run_test(subtest, subtest.iterations, subtest.retries,
610 set_layout=False)
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800611 else:
612 # This should never happen, there must be something wrong.
613 # However, we can't raise an exception, otherwise goofy will be closed
614 logging.critical(
615 'Goofy should not get a non-leaf test that is not parallel: %r',
616 test)
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800617 session.console.critical(
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800618 'Goofy should not get a non-leaf test that is not parallel: %r',
619 test)
Jon Salz5f2a0672012-05-22 17:14:06 +0800620
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800621 def run(self):
622 """Runs Goofy."""
623 # Process events forever.
624 while self.run_once(True):
625 pass
626
627 def run_enqueue(self, val):
628 """Enqueues an object on the event loop.
629
630 Generally this is a function. It may also be None to indicate that the
631 run queue should shut down.
632 """
633 self.run_queue.put(val)
634
635 def run_once(self, block=False):
636 """Runs all items pending in the event loop.
637
638 Args:
639 block: If true, block until at least one event is processed.
640
641 Returns:
642 True to keep going or False to shut down.
643 """
644 events = type_utils.DrainQueue(self.run_queue)
645 while not events:
646 # Nothing on the run queue.
647 self._run_queue_idle()
648 if block:
649 # Block for at least one event...
650 try:
651 events.append(self.run_queue.get(timeout=RUN_QUEUE_TIMEOUT_SECS))
652 except Queue.Empty:
653 # Keep going (calling _run_queue_idle() again at the top of
654 # the loop)
655 continue
656 # ...and grab anything else that showed up at the same
657 # time.
658 events.extend(type_utils.DrainQueue(self.run_queue))
659 else:
660 break
661
662 for event in events:
663 if not event:
664 # Shutdown request.
665 self.run_queue.task_done()
666 return False
667
668 try:
669 event()
670 except Exception:
671 logging.exception('Error in event loop')
672 self.record_exception(traceback.format_exception_only(
673 *sys.exc_info()[:2]))
674 # But keep going
675 finally:
676 self.run_queue.task_done()
677 return True
678
679 def _run_queue_idle(self):
680 """Invoked when the run queue has no events.
681
682 This method must not raise exception.
683 """
684 now = time.time()
685 if (self.last_idle and
686 now < (self.last_idle + RUN_QUEUE_TIMEOUT_SECS - 1)):
687 # Don't run more often than once every (RUN_QUEUE_TIMEOUT_SECS -
688 # 1) seconds.
689 return
690
691 self.last_idle = now
692 self.perform_periodic_tasks()
693
694 def check_exceptions(self):
695 """Raises an error if any exceptions have occurred in
696 invocation threads.
697 """
698 if self.exceptions:
699 raise RuntimeError('Exception in invocation thread: %r' %
700 self.exceptions)
701
702 def record_exception(self, msg):
703 """Records an exception in an invocation thread.
704
705 An exception with the given message will be rethrown when
706 Goofy is destroyed.
707 """
708 self.exceptions.append(msg)
709
710 @staticmethod
711 def drain_nondaemon_threads():
712 """Wait for all non-current non-daemon threads to exit.
713
714 This is performed by the Python runtime in an atexit handler,
715 but this implementation allows us to do more detailed logging, and
716 to support control-C for abrupt shutdown.
717 """
718 cur_thread = threading.current_thread()
719 all_threads_joined = False
720 while not all_threads_joined:
721 for thread in threading.enumerate():
722 if not thread.daemon and thread.is_alive() and thread is not cur_thread:
723 logging.info("Waiting for thread '%s'...", thread.name)
724 thread.join()
725 # We break rather than continue on because the thread list
726 # may have changed while we waited
727 break
728 else:
729 # No threads remain
730 all_threads_joined = True
731 return all_threads_joined
732
733 @staticmethod
734 def run_main_and_exit():
735 """Instantiate the receiver, run its main function, and exit when done.
736
737 This static method is the "entry point" for Goofy.
738 It instantiates the receiver and invokes its main function, while
739 handling exceptions. When main() finishes (normally or via an exception),
740 it exits the process.
741 """
742 try:
743 cls = Goofy
744 goofy = cls()
745 except Exception:
746 logging.info('Failed to instantiate %s, shutting down.', cls.__name__)
747 traceback.print_exc()
748 os._exit(1) # pylint: disable=protected-access
749 sys.exit(1)
750
751 try:
752 goofy.main()
753 except SystemExit:
754 # Propagate SystemExit without logging.
755 raise
756 except KeyboardInterrupt:
757 logging.info('Interrupted, shutting down...')
758 except Exception:
759 # Log the error before trying to shut down
760 logging.exception('Error in main loop')
761 raise
762 finally:
763 try:
764 # We drain threads manually, rather than letting Python do it,
765 # so that we can report to the user which threads are stuck
766 goofy.destroy()
767 cls.drain_nondaemon_threads()
768 except (KeyboardInterrupt, Exception):
769 # We got a keyboard interrupt while attempting to shut down.
770 # The user is waiting impatiently! This can happen if threads get stuck.
771 # We need to exit via os._exit, not sys.exit, because sys.exit() will
772 # run the main thread's atexit handler, which waits for all threads to
773 # exit, which is likely how we got stuck in the first place. However, we
774 # do want to capture all logs, so we shut down logging gracefully.
775 logging.info('Graceful shutdown interrupted, shutting down abruptly')
776 logging.shutdown()
777 os._exit(1) # pylint: disable=protected-access
778 # Normal exit path
779 sys.exit(0)
780
Earl Oua3bca122016-10-21 16:00:30 +0800781 def check_plugins(self):
782 """Check plugins to be paused or resumed."""
783 exclusive_resources = set()
784 for test in self.invocations:
785 exclusive_resources = exclusive_resources.union(
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800786 test.GetExclusiveResources())
Earl Oua3bca122016-10-21 16:00:30 +0800787 self.plugin_controller.PauseAndResumePluginByResource(exclusive_resources)
788
cychiang21886742012-07-05 15:16:32 +0800789 def check_for_updates(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800790 """Schedules an asynchronous check for updates if necessary."""
cychiang21886742012-07-05 15:16:32 +0800791 if not self.test_list.options.update_period_secs:
792 # Not enabled.
793 return
794
795 now = time.time()
796 if self.last_update_check and (
797 now - self.last_update_check <
798 self.test_list.options.update_period_secs):
799 # Not yet time for another check.
800 return
801
802 self.last_update_check = now
803
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800804 def handle_check_for_update(
Hung-Te Lind151bf32017-08-30 11:05:47 +0800805 reached_server, toolkit_version, needs_update):
806 if reached_server:
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800807 new_update_toolkit_version = toolkit_version if needs_update else None
808 if self.dut.info.update_toolkit_version != new_update_toolkit_version:
809 logging.info('Received new update TOOLKIT_VERSION: %s',
810 new_update_toolkit_version)
811 self.dut.info.Overrides('update_toolkit_version',
812 new_update_toolkit_version)
Peter Ammon1e1ec572014-06-26 17:56:32 -0700813 self.run_enqueue(self.update_system_info)
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800814 elif not self._suppress_periodic_update_messages:
815 logging.warning('Suppress error messages for periodic update checking '
816 'after the first one.')
817 self._suppress_periodic_update_messages = True
cychiang21886742012-07-05 15:16:32 +0800818
819 updater.CheckForUpdateAsync(
Hung-Te Lind151bf32017-08-30 11:05:47 +0800820 handle_check_for_update, None, self._suppress_periodic_update_messages)
cychiang21886742012-07-05 15:16:32 +0800821
Jon Salza6711d72012-07-18 14:33:03 +0800822 def cancel_pending_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800823 """Cancels any tests in the run queue."""
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800824 self.run_tests(None)
Jon Salza6711d72012-07-18 14:33:03 +0800825
Ricky Liang4bff3e32014-02-20 18:46:11 +0800826 def restore_active_run_state(self):
827 """Restores active run id and the list of scheduled tests."""
828 self.run_id = self.state_instance.get_shared_data('run_id', optional=True)
829 self.scheduled_run_tests = self.state_instance.get_shared_data(
830 'scheduled_run_tests', optional=True)
831
832 def set_active_run_state(self):
833 """Sets active run id and the list of scheduled tests."""
834 self.run_id = str(uuid.uuid4())
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800835 # try our best to predict which tests will be run.
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800836 self.scheduled_run_tests = self.test_list_iterator.GetPendingTests()
Ricky Liang4bff3e32014-02-20 18:46:11 +0800837 self.state_instance.set_shared_data('run_id', self.run_id)
838 self.state_instance.set_shared_data('scheduled_run_tests',
839 self.scheduled_run_tests)
840
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800841 def run_tests(self, subtree, status_filter=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800842 """Runs tests under subtree.
Jon Salz258a40c2012-04-19 12:34:01 +0800843
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800844 Run tests under a given subtree.
Jon Salzb1b39092012-05-03 02:05:09 +0800845
Ricky Liang6fe218c2013-12-27 15:17:17 +0800846 Args:
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800847 subtree: root of subtree to run or None to run nothing.
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +0800848 status_filter: List of available test states. Only run the tests which
849 states are in the list. Set to None if all test states are available.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800850 """
Hung-Te Lin793d6572017-09-04 18:17:56 +0800851 self.hooks.OnTestStart()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800852 self.test_list_iterator = TestListIterator(
853 subtree, status_filter, self.test_list)
854 if subtree is not None:
Ricky Liang4bff3e32014-02-20 18:46:11 +0800855 self.set_active_run_state()
Jon Salz0697cbf2012-07-04 15:14:04 +0800856 self.run_next_test()
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800857
Jon Salz0697cbf2012-07-04 15:14:04 +0800858 def reap_completed_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800859 """Removes completed tests from the set of active tests.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800860 """
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800861 test_completed = False
Jon Salz0697cbf2012-07-04 15:14:04 +0800862 for t, v in dict(self.invocations).iteritems():
863 if v.is_completed():
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800864 test_completed = True
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800865 new_state = t.UpdateState(**v.update_state_on_completion)
Jon Salz0697cbf2012-07-04 15:14:04 +0800866 del self.invocations[t]
867
Johny Lin62ed2a32015-05-13 11:57:12 +0800868 # Stop on failure if flag is true and there is no retry chances.
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800869 if (self.test_list.options.stop_on_failure and
Johny Lin62ed2a32015-05-13 11:57:12 +0800870 new_state.retries_left < 0 and
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800871 new_state.status == TestState.FAILED):
872 # Clean all the tests to cause goofy to stop.
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800873 session.console.info('Stop on failure triggered. Empty the queue.')
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800874 self.cancel_pending_tests()
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800875
Jon Salz1acc8742012-07-17 17:45:55 +0800876 if new_state.iterations_left and new_state.status == TestState.PASSED:
877 # Play it again, Sam!
878 self._run_test(t)
Cheng-Yi Chiangce05c002013-04-04 02:13:17 +0800879 # new_state.retries_left is obtained after update.
880 # For retries_left == 0, test can still be run for the last time.
881 elif (new_state.retries_left >= 0 and
882 new_state.status == TestState.FAILED):
883 # Still have to retry, Sam!
884 self._run_test(t)
Jon Salz1acc8742012-07-17 17:45:55 +0800885
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800886 if test_completed:
Vic Yangf01c59f2013-04-19 17:37:56 +0800887 self.log_watcher.KickWatchThread()
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800888
Jon Salz6dc031d2013-06-19 13:06:23 +0800889 def kill_active_tests(self, abort, root=None, reason=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800890 """Kills and waits for all active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +0800891
Jon Salz85a39882012-07-05 16:45:04 +0800892 Args:
893 abort: True to change state of killed tests to FAILED, False for
Jon Salz0697cbf2012-07-04 15:14:04 +0800894 UNTESTED.
Jon Salz85a39882012-07-05 16:45:04 +0800895 root: If set, only kills tests with root as an ancestor.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800896 reason: If set, the abort reason.
897 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800898 self.reap_completed_tests()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800899 # since we remove objects while iterating, make a copy
900 for test, invoc in dict(self.invocations).iteritems():
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800901 if root and not test.HasAncestor(root):
Jon Salz85a39882012-07-05 16:45:04 +0800902 continue
903
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800904 session.console.info('Killing active test %s...', test.path)
Jon Salz6dc031d2013-06-19 13:06:23 +0800905 invoc.abort_and_join(reason)
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800906 session.console.info('Killed %s', test.path)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800907 test.UpdateState(**invoc.update_state_on_completion)
Jon Salz0697cbf2012-07-04 15:14:04 +0800908 del self.invocations[test]
Jon Salz1acc8742012-07-17 17:45:55 +0800909
Jon Salz0697cbf2012-07-04 15:14:04 +0800910 if not abort:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800911 test.UpdateState(status=TestState.UNTESTED)
Jon Salz0697cbf2012-07-04 15:14:04 +0800912 self.reap_completed_tests()
913
Jon Salz6dc031d2013-06-19 13:06:23 +0800914 def stop(self, root=None, fail=False, reason=None):
915 self.kill_active_tests(fail, root, reason)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800916
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800917 self.test_list_iterator.Stop(root)
Jon Salz85a39882012-07-05 16:45:04 +0800918 self.run_next_test()
Jon Salz0697cbf2012-07-04 15:14:04 +0800919
Jon Salz4712ac72013-02-07 17:12:05 +0800920 def clear_state(self, root=None):
Jon Salzd7550792013-07-12 05:49:27 +0800921 if root is None:
922 root = self.test_list
Jon Salz6dc031d2013-06-19 13:06:23 +0800923 self.stop(root, reason='Clearing test state')
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800924 for f in root.Walk():
925 if f.IsLeaf():
926 f.UpdateState(status=TestState.UNTESTED)
Jon Salz4712ac72013-02-07 17:12:05 +0800927
Jon Salz6dc031d2013-06-19 13:06:23 +0800928 def abort_active_tests(self, reason=None):
929 self.kill_active_tests(True, reason=reason)
Jon Salz0697cbf2012-07-04 15:14:04 +0800930
931 def main(self):
Jon Salzeff94182013-06-19 15:06:28 +0800932 syslog.openlog('goofy')
933
Jon Salz0697cbf2012-07-04 15:14:04 +0800934 try:
Jon Salzd7550792013-07-12 05:49:27 +0800935 self.status = Status.INITIALIZING
Jon Salz0697cbf2012-07-04 15:14:04 +0800936 self.init()
937 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +0800938 success=True)
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800939 testlog.Log(
Joel Kitching9eb203a2016-04-21 15:36:30 +0800940 testlog.StationInit({
Hung-Te Linda8eb992017-09-28 03:27:12 +0800941 'stationDeviceId': session.GetDeviceID(),
942 'stationInstallationId': session.GetInstallationID(),
943 'count': session.GetInitCount(),
Joel Kitching9eb203a2016-04-21 15:36:30 +0800944 'success': True}))
Hung-Te Linc8174b52017-06-02 11:11:45 +0800945 except Exception:
Joel Kitching9eb203a2016-04-21 15:36:30 +0800946 try:
947 if self.event_log:
Jon Salz0697cbf2012-07-04 15:14:04 +0800948 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +0800949 success=False,
950 trace=traceback.format_exc())
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800951 if self.testlog:
952 testlog.Log(
Joel Kitching9eb203a2016-04-21 15:36:30 +0800953 testlog.StationInit({
Hung-Te Linda8eb992017-09-28 03:27:12 +0800954 'stationDeviceId': session.GetDeviceID(),
955 'stationInstallationId': session.GetInstallationID(),
956 'count': session.GetInitCount(),
Joel Kitching9eb203a2016-04-21 15:36:30 +0800957 'success': False,
958 'failureMessage': traceback.format_exc()}))
Hung-Te Linc8174b52017-06-02 11:11:45 +0800959 except Exception:
Joel Kitching9eb203a2016-04-21 15:36:30 +0800960 pass
Jon Salz0697cbf2012-07-04 15:14:04 +0800961 raise
962
Jon Salzd7550792013-07-12 05:49:27 +0800963 self.status = Status.RUNNING
Jon Salzeff94182013-06-19 15:06:28 +0800964 syslog.syslog('Goofy (factory test harness) starting')
Chun-Ta Lin5d12b592015-06-30 00:54:23 -0700965 syslog.syslog('Boot sequence = %d' % GetBootSequence())
Hung-Te Linda8eb992017-09-28 03:27:12 +0800966 syslog.syslog('Goofy init count = %d' % session.GetInitCount())
Jon Salz0697cbf2012-07-04 15:14:04 +0800967 self.run()
968
969 def update_system_info(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800970 """Updates system info."""
Shen-En Shihce8ffe02017-08-01 18:58:09 +0800971 logging.info('Received a notify to update system info.')
972 self.dut.info.Invalidate()
973
974 # Propagate this notify to goofy components
975 try:
976 status_monitor = plugin_controller.GetPluginRPCProxy(
977 'status_monitor.status_monitor')
978 status_monitor.UpdateDeviceInfo()
979 except Exception:
980 logging.debug('Failed to update status monitor plugin.')
Jon Salz0697cbf2012-07-04 15:14:04 +0800981
Wei-Han Chen8d7fbc42017-10-18 19:20:47 +0800982 def set_force_auto_run(self):
983 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, FORCE_AUTO_RUN)
984
Jon Salzeb42f0d2012-07-27 19:14:04 +0800985 def update_factory(self, auto_run_on_restart=False, post_update_hook=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800986 """Commences updating factory software.
Jon Salzeb42f0d2012-07-27 19:14:04 +0800987
988 Args:
989 auto_run_on_restart: Auto-run when the machine comes back up.
990 post_update_hook: Code to call after update but immediately before
991 restart.
992
993 Returns:
994 Never if the update was successful (we just reboot).
995 False if the update was unnecessary (no update available).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800996 """
Jon Salz6dc031d2013-06-19 13:06:23 +0800997 self.kill_active_tests(False, reason='Factory software update')
Jon Salza6711d72012-07-18 14:33:03 +0800998 self.cancel_pending_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +0800999
Jon Salz5c344f62012-07-13 14:31:16 +08001000 def pre_update_hook():
1001 if auto_run_on_restart:
Wei-Han Chen8d7fbc42017-10-18 19:20:47 +08001002 self.set_force_auto_run()
Jon Salz5c344f62012-07-13 14:31:16 +08001003 self.state_instance.close()
1004
Jon Salzeb42f0d2012-07-27 19:14:04 +08001005 if updater.TryUpdate(pre_update_hook=pre_update_hook):
1006 if post_update_hook:
1007 post_update_hook()
1008 self.env.shutdown('reboot')
Jon Salz0697cbf2012-07-04 15:14:04 +08001009
chuntsen9d675c62017-06-20 14:35:30 +08001010 def handle_signal(self, signum, unused_frame):
1011 names = [signame for signame in dir(signal) if signame.startswith('SIG') and
1012 getattr(signal, signame) == signum]
1013 signal_name = ', '.join(names) if names else 'UNKNOWN'
1014 logging.error('Received signal %s(%d)', signal_name, signum)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001015 self.run_enqueue(None)
Jon Salz77c151e2012-08-28 07:20:37 +08001016 raise KeyboardInterrupt()
1017
Jon Salz128b0932013-07-03 16:55:26 +08001018 def GetTestList(self, test_list_id):
1019 """Returns the test list with the given ID.
1020
1021 Raises:
1022 TestListError: The test list ID is not valid.
1023 """
1024 try:
1025 return self.test_lists[test_list_id]
1026 except KeyError:
Peter Shihd14623e2017-11-14 15:12:54 +08001027 raise type_utils.TestListError(
Wei-Han Chendbc0fa22017-09-28 10:29:53 +08001028 '%r is not a valid test list ID (available IDs are %r)' % (
1029 test_list_id, sorted(self.test_lists.keys())))
Jon Salz128b0932013-07-03 16:55:26 +08001030
Chih-Yu Huang1725d622017-03-24 16:08:35 +08001031 def _RecordStartError(self, error_message):
1032 """Appends the startup error message into the shared data."""
1033 KEY = 'startup_error'
1034 data = self.state_instance.get_shared_data(KEY, optional=True)
1035 new_data = '%s\n\n%s' % (data, error_message) if data else error_message
1036 self.state_instance.set_shared_data(KEY, new_data)
1037
Jon Salz128b0932013-07-03 16:55:26 +08001038 def InitTestLists(self):
Joel Kitching50a63ea2016-02-22 13:15:09 +08001039 """Reads in all test lists and sets the active test list.
1040
1041 Returns:
1042 True if the active test list could be set, False if failed.
1043 """
1044 startup_errors = []
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +08001045
1046 self.test_lists, failed_files = self.test_list_manager.BuildAllTestLists()
1047
Wei-Han Chendbc0fa22017-09-28 10:29:53 +08001048 logging.info('Loaded test lists: %r', sorted(self.test_lists.keys()))
Jon Salz128b0932013-07-03 16:55:26 +08001049
Joel Kitching50a63ea2016-02-22 13:15:09 +08001050 # Check for any syntax errors in test list files.
1051 if failed_files:
1052 logging.info('Failed test list files: [%s]',
1053 ' '.join(failed_files.keys()))
1054 for f, exc_info in failed_files.iteritems():
1055 logging.error('Error in test list file: %s', f,
1056 exc_info=exc_info)
1057
1058 # Limit the stack trace to the very last entry.
1059 exc_type, exc_value, exc_traceback = exc_info
1060 while exc_traceback and exc_traceback.tb_next:
1061 exc_traceback = exc_traceback.tb_next
1062
1063 exc_string = ''.join(
1064 traceback.format_exception(
1065 exc_type, exc_value, exc_traceback)).rstrip()
1066 startup_errors.append('Error in test list file (%s):\n%s'
1067 % (f, exc_string))
1068
Jon Salz128b0932013-07-03 16:55:26 +08001069 if not self.options.test_list:
Hung-Te Linab78fc42017-09-22 00:21:57 +08001070 self.options.test_list = self.test_list_manager.GetActiveTestListId()
Jon Salz128b0932013-07-03 16:55:26 +08001071
Joel Kitching50a63ea2016-02-22 13:15:09 +08001072 # Check for a non-existent test list ID.
1073 try:
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001074 self.test_list = self.GetTestList(self.options.test_list)
Joel Kitching50a63ea2016-02-22 13:15:09 +08001075 logging.info('Active test list: %s', self.test_list.test_list_id)
Peter Shihd14623e2017-11-14 15:12:54 +08001076 except type_utils.TestListError as e:
Joel Kitching50a63ea2016-02-22 13:15:09 +08001077 logging.exception('Invalid active test list: %s',
1078 self.options.test_list)
1079 startup_errors.append(e.message)
Jon Salz128b0932013-07-03 16:55:26 +08001080
Joel Kitching50a63ea2016-02-22 13:15:09 +08001081 # Show all startup errors.
1082 if startup_errors:
Chih-Yu Huang1725d622017-03-24 16:08:35 +08001083 self._RecordStartError('\n\n'.join(startup_errors))
Joel Kitching50a63ea2016-02-22 13:15:09 +08001084
1085 # Only return False if failed to load the active test list.
1086 return bool(self.test_list)
Jon Salz128b0932013-07-03 16:55:26 +08001087
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001088 def init_hooks(self):
1089 """Initializes hooks.
1090
1091 Must run after self.test_list ready.
1092 """
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001093 module, cls = self.test_list.options.hooks_class.rsplit('.', 1)
1094 self.hooks = getattr(__import__(module, fromlist=[cls]), cls)()
Wei-Han Chen1a114682017-10-02 10:33:54 +08001095 assert isinstance(self.hooks, hooks.Hooks), (
Ricky Liang45c73e72015-01-15 15:00:30 +08001096 'hooks should be of type Hooks but is %r' % type(self.hooks))
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001097 self.hooks.test_list = self.test_list
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001098 self.hooks.OnCreatedTestList()
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001099
Vic Yanga3cecf82014-12-26 00:44:21 -08001100 def init_ui(self):
1101 """Initialize UI."""
Shen-En Shih65619f42017-10-02 16:52:10 +08001102 logging.info('Waiting for a web socket connection')
1103 self.web_socket_manager.wait()
Vic Yanga3cecf82014-12-26 00:44:21 -08001104 self._ui_initialized = True
Vic Yanga3cecf82014-12-26 00:44:21 -08001105
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001106 @staticmethod
1107 def GetCommandLineArgsParser():
1108 """Returns a parser for Goofy command line arguments."""
Jon Salz0697cbf2012-07-04 15:14:04 +08001109 parser = OptionParser()
1110 parser.add_option('-v', '--verbose', dest='verbose',
Jon Salz8fa8e832012-07-13 19:04:09 +08001111 action='store_true',
1112 help='Enable debug logging')
Jon Salz0697cbf2012-07-04 15:14:04 +08001113 parser.add_option('--print_test_list', dest='print_test_list',
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001114 metavar='TEST_LIST_ID',
1115 help='Print the content of TEST_LIST_ID and exit')
Jon Salz0697cbf2012-07-04 15:14:04 +08001116 parser.add_option('--restart', dest='restart',
Jon Salz8fa8e832012-07-13 19:04:09 +08001117 action='store_true',
1118 help='Clear all test state')
Jon Salz0697cbf2012-07-04 15:14:04 +08001119 parser.add_option('--test_list', dest='test_list',
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001120 metavar='TEST_LIST_ID',
1121 help='Use test list whose id is TEST_LIST_ID')
Ricky Liang6fe218c2013-12-27 15:17:17 +08001122 parser.add_option('--automation-mode',
1123 choices=[m.lower() for m in AutomationMode],
Ricky Liang45c73e72015-01-15 15:00:30 +08001124 default='none', help='Factory test automation mode.')
Ricky Liang117484a2014-04-14 11:14:41 +08001125 parser.add_option('--no-auto-run-on-start', dest='auto_run_on_start',
1126 action='store_false', default=True,
1127 help=('do not automatically run the test list on goofy '
1128 'start; this is only valid when factory test '
1129 'automation is enabled'))
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001130 return parser
1131
1132 def init(self, args=None, env=None):
1133 """Initializes Goofy.
1134
1135 Args:
Shen-En Shihe05cbbc2017-10-02 16:47:30 +08001136 args: A list of command-line arguments. Uses sys.argv if args is None.
1137 env: An Environment instance to use (or None to use DUTEnvironment).
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001138 """
1139 (self.options, self.args) = self.GetCommandLineArgsParser().parse_args(args)
Jon Salz0697cbf2012-07-04 15:14:04 +08001140
Joel Kitching261e0422017-03-30 16:52:01 -07001141 signal.signal(signal.SIGINT, self.handle_signal)
1142 signal.signal(signal.SIGTERM, self.handle_signal)
Hung-Te Lina846f602014-07-04 20:32:22 +08001143 # TODO(hungte) SIGTERM does not work properly without Telemetry and should
1144 # be fixed.
Hung-Te Lina846f602014-07-04 20:32:22 +08001145
Jon Salz46b89562012-07-05 11:49:22 +08001146 # Make sure factory directories exist.
Peter Shihb4e49352017-05-25 17:35:11 +08001147 for path in [
1148 paths.DATA_LOG_DIR, paths.DATA_STATE_DIR, paths.DATA_TESTS_DIR]:
1149 file_utils.TryMakeDirs(path)
Jon Salz46b89562012-07-05 11:49:22 +08001150
Wei-Han Chen78f35f62017-03-06 20:11:20 +08001151 try:
1152 goofy_default_options = config_utils.LoadConfig(validate_schema=False)
1153 for key, value in goofy_default_options.iteritems():
1154 if getattr(self.options, key, None) is None:
1155 logging.info('self.options.%s = %r', key, value)
1156 setattr(self.options, key, value)
1157 except Exception:
1158 logging.exception('failed to load goofy overriding options')
1159
Jon Salz0f996602012-10-03 15:26:48 +08001160 if self.options.print_test_list:
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +08001161 all_test_lists, unused_errors = self.test_list_manager.BuildAllTestLists()
1162 test_list = (
1163 all_test_lists[self.options.print_test_list].ToFactoryTestList())
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001164 print(test_list.__repr__(recursive=True))
Jon Salz0f996602012-10-03 15:26:48 +08001165 sys.exit(0)
1166
Jon Salzee85d522012-07-17 14:34:46 +08001167 event_log.IncrementBootSequence()
Hung-Te Linda8eb992017-09-28 03:27:12 +08001168 session.IncrementInitCount()
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +08001169
Jon Salzd15bbcf2013-05-21 17:33:57 +08001170 # Don't defer logging the initial event, so we can make sure
1171 # that device_id, reimage_id, etc. are all set up.
1172 self.event_log = EventLog('goofy', defer=False)
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +08001173 self.testlog = testlog.Testlog(
Peter Shihb4e49352017-05-25 17:35:11 +08001174 log_root=paths.DATA_LOG_DIR, uuid=self.uuid,
Hung-Te Linda8eb992017-09-28 03:27:12 +08001175 stationDeviceId=session.GetDeviceID(),
1176 stationInstallationId=session.GetInstallationID())
Jon Salz0697cbf2012-07-04 15:14:04 +08001177
Jon Salz0697cbf2012-07-04 15:14:04 +08001178 if env:
1179 self.env = env
Shen-En Shihe05cbbc2017-10-02 16:47:30 +08001180 else:
Ricky Liang09d66d82014-09-25 11:20:54 +08001181 self.env = test_environment.DUTEnvironment()
Jon Salz0697cbf2012-07-04 15:14:04 +08001182 self.env.goofy = self
1183
1184 if self.options.restart:
1185 state.clear_state()
1186
Earl Ouacbe99c2017-02-21 16:04:19 +08001187 self.start_goofy_server()
Peter Shihbb771342017-10-19 16:42:28 +08001188 # The i18n files need to be ready before index.html is loaded.
Peter Shih80e78b42017-03-10 17:00:56 +08001189 self.init_i18n()
Peter Shihbb771342017-10-19 16:42:28 +08001190 self.init_static_files()
1191 self.init_state_instance()
Jon Salz0697cbf2012-07-04 15:14:04 +08001192 self.last_shutdown_time = (
Ricky Liang45c73e72015-01-15 15:00:30 +08001193 self.state_instance.get_shared_data('shutdown_time', optional=True))
Jon Salz0697cbf2012-07-04 15:14:04 +08001194 self.state_instance.del_shared_data('shutdown_time', optional=True)
Jon Salzb19ea072013-02-07 16:35:00 +08001195 self.state_instance.del_shared_data('startup_error', optional=True)
Jon Salz0697cbf2012-07-04 15:14:04 +08001196
Ricky Liang6fe218c2013-12-27 15:17:17 +08001197 self.options.automation_mode = ParseAutomationMode(
1198 self.options.automation_mode)
1199 self.state_instance.set_shared_data('automation_mode',
1200 self.options.automation_mode)
1201 self.state_instance.set_shared_data(
1202 'automation_mode_prompt',
1203 AutomationModePrompt[self.options.automation_mode])
1204
Joel Kitching50a63ea2016-02-22 13:15:09 +08001205 success = False
Jon Salz128b0932013-07-03 16:55:26 +08001206 try:
Joel Kitching50a63ea2016-02-22 13:15:09 +08001207 success = self.InitTestLists()
Hung-Te Linc8174b52017-06-02 11:11:45 +08001208 except Exception:
Shen-En Shih44107d12017-10-02 11:31:12 +08001209 logging.exception('Unable to initialize test lists')
1210 self._RecordStartError(
1211 'Unable to initialize test lists\n%s' % traceback.format_exc())
Joel Kitching50a63ea2016-02-22 13:15:09 +08001212
1213 if not success:
Shen-En Shih65619f42017-10-02 16:52:10 +08001214 # Create an empty test list with default options so that the rest of
1215 # startup can proceed.
1216 # A message box will pop up in UI for the error details.
Wei-Han Chena14210e2017-10-16 14:07:52 +08001217 self.test_list = manager.DummyTestList(self.test_list_manager)
1218
1219 self.test_list.state_instance = self.state_instance
Jon Salzb19ea072013-02-07 16:35:00 +08001220
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001221 self.init_hooks()
1222
Jon Salz822838b2013-03-25 17:32:33 +08001223 if self.test_list.options.clear_state_on_start:
1224 self.state_instance.clear_test_state()
1225
Jon Salz670ce062014-05-16 15:53:50 +08001226 # If the phase is invalid, this will raise a ValueError.
1227 phase.SetPersistentPhase(self.test_list.options.phase)
1228
Peter Shih3b0bb9f2017-03-21 16:23:32 +08001229 if not self.state_instance.has_shared_data('ui_locale'):
Hung-Te Lin134403c2017-08-23 17:30:17 +08001230 ui_locale = self.test_list.options.ui_locale
Peter Shih3b0bb9f2017-03-21 16:23:32 +08001231 self.state_instance.set_shared_data('ui_locale', ui_locale)
Jon Salz0697cbf2012-07-04 15:14:04 +08001232 self.state_instance.set_shared_data(
Ricky Liang45c73e72015-01-15 15:00:30 +08001233 'test_list_options',
Peter Shih90425db2017-08-02 15:53:48 +08001234 self.test_list.options.ToDict())
Jon Salz0697cbf2012-07-04 15:14:04 +08001235 self.state_instance.test_list = self.test_list
1236
1237 self.init_states()
1238 self.start_event_server()
Hung-Te Lincc41d2a2014-10-29 13:35:20 +08001239
Earl Oua3bca122016-10-21 16:00:30 +08001240 # Load and run Goofy plugins.
1241 self.plugin_controller = plugin_controller.PluginController(
1242 self.test_list.options.plugin_config_name, self)
1243 self.plugin_controller.StartAllPlugins()
1244
Chih-Yu Huang97103ae2017-03-20 18:22:54 +08001245 # TODO(akahuang): Move this part into a pytest.
1246 # Prepare DUT link after the plugins start running, because the link might
1247 # need the network connection.
1248 if success:
1249 try:
1250 if self.test_list.options.dut_options:
1251 logging.info('dut_options set by %s: %r', self.test_list.test_list_id,
1252 self.test_list.options.dut_options)
1253 device_utils.PrepareDUTLink(**self.test_list.options.dut_options)
1254 except Exception:
1255 logging.exception('Unable to prepare DUT link.')
Chih-Yu Huang1725d622017-03-24 16:08:35 +08001256 self._RecordStartError(
Chih-Yu Huang97103ae2017-03-20 18:22:54 +08001257 'Unable to prepare DUT link.\n%s' % traceback.format_exc())
1258
Jon Salz0697cbf2012-07-04 15:14:04 +08001259 # Note that we create a log watcher even if
1260 # sync_event_log_period_secs isn't set (no background
1261 # syncing), since we may use it to flush event logs as well.
1262 self.log_watcher = EventLogWatcher(
Ricky Liang45c73e72015-01-15 15:00:30 +08001263 self.test_list.options.sync_event_log_period_secs,
1264 event_log_db_file=None,
1265 handle_event_logs_callback=self.handle_event_logs)
Jon Salz0697cbf2012-07-04 15:14:04 +08001266 if self.test_list.options.sync_event_log_period_secs:
1267 self.log_watcher.StartWatchThread()
1268
Shen-En Shihf4ad32f2017-07-31 15:56:39 +08001269 self.event_client.post_event(
1270 Event(Event.Type.UPDATE_SYSTEM_INFO))
Jon Salz0697cbf2012-07-04 15:14:04 +08001271
1272 os.environ['CROS_FACTORY'] = '1'
1273 os.environ['CROS_DISABLE_SITE_SYSINFO'] = '1'
1274
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001275 # Should not move earlier.
1276 self.hooks.OnStartup()
1277
Ricky Liang36512a32014-07-25 11:47:04 +08001278 # Only after this point the Goofy backend is ready for UI connection.
1279 self.ready_for_ui_connection = True
1280
Jon Salz0697cbf2012-07-04 15:14:04 +08001281 def state_change_callback(test, test_state):
1282 self.event_client.post_event(
Peter Shihd46c5fd2017-09-22 15:28:42 +08001283 Event(
1284 Event.Type.STATE_CHANGE,
1285 path=test.path,
1286 state=test_state.ToStruct()))
Jon Salz0697cbf2012-07-04 15:14:04 +08001287 self.test_list.state_change_callback = state_change_callback
Jon Salz73e0fd02012-04-04 11:46:38 +08001288
Vic Yange2c76a82014-10-30 12:48:19 -07001289 self.pytest_prespawner = prespawner.PytestPrespawner()
1290 self.pytest_prespawner.start()
Jon Salza6711d72012-07-18 14:33:03 +08001291
Ricky Liang48e47f92014-02-26 19:31:51 +08001292 tests_after_shutdown = self.state_instance.get_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001293 TESTS_AFTER_SHUTDOWN, optional=True)
Jon Salz5c344f62012-07-13 14:31:16 +08001294 force_auto_run = (tests_after_shutdown == FORCE_AUTO_RUN)
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001295
Jon Salz5c344f62012-07-13 14:31:16 +08001296 if not force_auto_run and tests_after_shutdown is not None:
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001297 logging.info('Resuming tests after shutdown: %r', tests_after_shutdown)
1298 self.test_list_iterator = tests_after_shutdown
Wei-Han Chenbcac7252017-04-21 19:46:51 +08001299 self.test_list_iterator.SetTestList(self.test_list)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001300 self.run_enqueue(self.run_next_test)
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001301 elif force_auto_run or self.test_list.options.auto_run_on_start:
1302 # If automation mode is enabled, allow suppress auto_run_on_start.
1303 if (self.options.automation_mode == 'NONE' or
1304 self.options.auto_run_on_start):
1305 status_filter = [TestState.UNTESTED]
1306 if self.test_list.options.retry_failed_on_start:
1307 status_filter.append(TestState.FAILED)
1308 self.run_enqueue(lambda: self.run_tests(self.test_list, status_filter))
1309 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, None)
Ricky Liang4bff3e32014-02-20 18:46:11 +08001310 self.restore_active_run_state()
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001311
Hung-Te Lin793d6572017-09-04 18:17:56 +08001312 self.hooks.OnTestStart()
Vic Yang08505c72015-01-06 17:01:53 -08001313
Dean Liao592e4d52013-01-10 20:06:39 +08001314 self.may_disable_cros_shortcut_keys()
1315
1316 def may_disable_cros_shortcut_keys(self):
1317 test_options = self.test_list.options
1318 if test_options.disable_cros_shortcut_keys:
1319 logging.info('Filter ChromeOS shortcut keys.')
1320 self.key_filter = KeyFilter(
1321 unmap_caps_lock=test_options.disable_caps_lock,
1322 caps_lock_keycode=test_options.caps_lock_keycode)
1323 self.key_filter.Start()
1324
Peter Ammon1e1ec572014-06-26 17:56:32 -07001325 def perform_periodic_tasks(self):
Hung-Te Lina452d4d2017-10-25 17:46:14 +08001326 """Perform any periodic work.
Vic Yang4953fc12012-07-26 16:19:53 +08001327
Peter Ammon1e1ec572014-06-26 17:56:32 -07001328 This method must not raise exceptions.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001329 """
Earl Oua3bca122016-10-21 16:00:30 +08001330 self.check_plugins()
cychiang21886742012-07-05 15:16:32 +08001331 self.check_for_updates()
Jon Salz57717ca2012-04-04 16:47:25 +08001332
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001333 def handle_event_logs(self, chunks, periodic=False):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001334 """Callback for event watcher.
Jon Salz258a40c2012-04-19 12:34:01 +08001335
Hung-Te Lind151bf32017-08-30 11:05:47 +08001336 Attempts to upload the event logs to the factory server.
Vic Yang93027612013-05-06 02:42:49 +08001337
1338 Args:
Jon Salzd15bbcf2013-05-21 17:33:57 +08001339 chunks: A list of Chunk objects.
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001340 periodic: This event log handling is periodic. Error messages
1341 will only be shown for the first time.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001342 """
Vic Yang93027612013-05-06 02:42:49 +08001343 first_exception = None
1344 exception_count = 0
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001345 # Suppress error messages for periodic event syncing except for the
1346 # first time. If event syncing is not periodic, always show the error
1347 # messages.
1348 quiet = self._suppress_event_log_error_messages if periodic else False
Vic Yang93027612013-05-06 02:42:49 +08001349
Jon Salzd15bbcf2013-05-21 17:33:57 +08001350 for chunk in chunks:
Vic Yang93027612013-05-06 02:42:49 +08001351 try:
Jon Salzcddb6402013-05-23 12:56:42 +08001352 description = 'event logs (%s)' % str(chunk)
Vic Yang93027612013-05-06 02:42:49 +08001353 start_time = time.time()
Hung-Te Lind151bf32017-08-30 11:05:47 +08001354 proxy = server_proxy.GetServerProxy(quiet=quiet)
1355 proxy.UploadEvent(
1356 chunk.log_name + '.' + event_log.GetReimageId(),
1357 Binary(chunk.chunk))
Vic Yang93027612013-05-06 02:42:49 +08001358 logging.info(
Ricky Liang45c73e72015-01-15 15:00:30 +08001359 'Successfully synced %s in %.03f s',
1360 description, time.time() - start_time)
Hung-Te Linc8174b52017-06-02 11:11:45 +08001361 except Exception:
Hung-Te Linf707b242016-01-08 23:11:42 +08001362 first_exception = (first_exception or
1363 (chunk.log_name + ': ' +
1364 debug_utils.FormatExceptionOnly()))
Vic Yang93027612013-05-06 02:42:49 +08001365 exception_count += 1
1366
1367 if exception_count:
1368 if exception_count == 1:
1369 msg = 'Log upload failed: %s' % first_exception
1370 else:
1371 msg = '%d log upload failed; first is: %s' % (
1372 exception_count, first_exception)
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001373 # For periodic event log syncing, only show the first error messages.
1374 if periodic:
1375 if not self._suppress_event_log_error_messages:
1376 self._suppress_event_log_error_messages = True
Hung-Te Lind151bf32017-08-30 11:05:47 +08001377 logging.warning('Suppress periodic factory server error messages for '
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001378 'event log syncing after the first one.')
1379 raise Exception(msg)
1380 # For event log syncing by request, show the error messages.
1381 else:
1382 raise Exception(msg)
Vic Yang93027612013-05-06 02:42:49 +08001383
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001384 def run_tests_with_status(self, statuses_to_run, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001385 """Runs all top-level tests with a particular status.
Jon Salz0405ab52012-03-16 15:26:52 +08001386
Jon Salz0697cbf2012-07-04 15:14:04 +08001387 All active tests, plus any tests to re-run, are reset.
Jon Salz57717ca2012-04-04 16:47:25 +08001388
Jon Salz0697cbf2012-07-04 15:14:04 +08001389 Args:
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001390 statuses_to_run: The particular status that caller wants to run.
Jon Salz0697cbf2012-07-04 15:14:04 +08001391 starting_at: If provided, only auto-runs tests beginning with
1392 this test.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001393 root: The root of tests to run. If not provided, it will be
1394 the root of all tests.
1395 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001396 root = root or self.test_list
Jon Salz6dc031d2013-06-19 13:06:23 +08001397 self.abort_active_tests('Operator requested run/re-run of certain tests')
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001398 self.run_tests(root, status_filter=statuses_to_run)
Jon Salz0405ab52012-03-16 15:26:52 +08001399
Jon Salz0697cbf2012-07-04 15:14:04 +08001400 def restart_tests(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001401 """Restarts all tests."""
Jon Salz0697cbf2012-07-04 15:14:04 +08001402 root = root or self.test_list
Jon Salz0405ab52012-03-16 15:26:52 +08001403
Jon Salz6dc031d2013-06-19 13:06:23 +08001404 self.abort_active_tests('Operator requested restart of certain tests')
Wei-Han Chen3ae204c2017-04-28 19:36:55 +08001405 for test in root.Walk():
1406 test.UpdateState(status=TestState.UNTESTED)
Jon Salz0697cbf2012-07-04 15:14:04 +08001407 self.run_tests(root)
Hung-Te Lin96632362012-03-20 21:14:18 +08001408
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001409 def auto_run(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001410 """"Auto-runs" tests that have not been run yet.
Hung-Te Lin96632362012-03-20 21:14:18 +08001411
Jon Salz0697cbf2012-07-04 15:14:04 +08001412 Args:
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001413 root: If provided, the root of tests to run. If not provided, the root
1414 will be test_list (root of all tests).
1415 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001416 root = root or self.test_list
1417 self.run_tests_with_status([TestState.UNTESTED, TestState.ACTIVE],
Ricky Liang45c73e72015-01-15 15:00:30 +08001418 root=root)
Jon Salz968e90b2012-03-18 16:12:43 +08001419
Wei-Ning Huang38b75f02015-02-25 18:25:14 +08001420 def handle_key_filter_mode(self, event):
1421 if self.key_filter:
1422 if getattr(event, 'enabled'):
1423 self.key_filter.Start()
1424 else:
1425 self.key_filter.Stop()
1426
Jon Salz0697cbf2012-07-04 15:14:04 +08001427 def wait(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001428 """Waits for all pending invocations.
Jon Salz0697cbf2012-07-04 15:14:04 +08001429
1430 Useful for testing.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001431 """
Jon Salz1acc8742012-07-17 17:45:55 +08001432 while self.invocations:
1433 for k, v in self.invocations.iteritems():
1434 logging.info('Waiting for %s to complete...', k)
1435 v.thread.join()
1436 self.reap_completed_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +08001437
Claire Changd1961a22015-08-05 16:15:55 +08001438 def test_fail(self, test):
Hung-Te Lin793d6572017-09-04 18:17:56 +08001439 self.hooks.OnTestFailure(test)
Claire Changd1961a22015-08-05 16:15:55 +08001440
Wei-Han Chenced08ef2016-11-08 09:40:02 +08001441
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001442def main():
1443 # Logging should be solved first.
1444 (options, unused_args) = Goofy.GetCommandLineArgsParser().parse_args()
Hung-Te Lin8fc0d652017-09-21 13:05:44 +08001445 log_utils.InitLogging(verbose=options.verbose)
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001446
Peter Ammona3d298c2014-09-23 10:11:02 -07001447 Goofy.run_main_and_exit()
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001448
1449
1450if __name__ == '__main__':
1451 main()