blob: e4e9fd6ce87889add7c06c699485c8a6f1d5c429 [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
Jon Salz77c151e2012-08-28 07:20:37 +080013import signal
Jon Salz0405ab52012-03-16 15:26:52 +080014import sys
Jon Salz0405ab52012-03-16 15:26:52 +080015import threading
16import time
17import traceback
Jon Salz258a40c2012-04-19 12:34:01 +080018import uuid
Jon Salzb10cf512012-08-09 17:29:21 +080019from xmlrpclib import Binary
Hung-Te Linf2f78f72012-02-08 19:27:11 +080020
Peter Shihfdf17682017-05-26 11:38:39 +080021import factory_common # pylint: disable=unused-import
Hung-Te Linb6287242016-05-18 14:39:05 +080022from cros.factory.device import device_utils
Vic Yangd80ea752014-09-24 16:07:14 +080023from cros.factory.goofy.goofy_base import GoofyBase
24from cros.factory.goofy.goofy_rpc import GoofyRPC
Earl Ouacbe99c2017-02-21 16:04:19 +080025from cros.factory.goofy import goofy_server
Vic Yangd80ea752014-09-24 16:07:14 +080026from cros.factory.goofy.invocation import TestInvocation
27from cros.factory.goofy.link_manager import PresenterLinkManager
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
41from cros.factory.test.event import EventClient
42from 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
Earl Oua3bca122016-10-21 16:00:30 +080047from cros.factory.test import factory
jcliangcd688182012-08-20 21:01:26 +080048from cros.factory.test.factory import TestState
Peter Shihce03c2e2017-03-21 17:36:10 +080049from cros.factory.test.i18n import html_translator
Peter Shihf65db932017-03-22 17:06:34 +080050from cros.factory.test.i18n import test_ui as i18n_test_ui
Peter Shih80e78b42017-03-10 17:00:56 +080051from cros.factory.test.i18n import translation
Hung-Te Lin3f096842016-01-13 17:37:06 +080052from cros.factory.test.rules import phase
Earl Oua3bca122016-10-21 16:00:30 +080053from cros.factory.test import shopfloor
54from cros.factory.test import state
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +080055from cros.factory.test.test_lists import manager
Wei-Han Chen2ebb92d2016-01-12 14:51:41 +080056from cros.factory.test.test_lists import test_lists
Earl Oua3bca122016-10-21 16:00:30 +080057from cros.factory.test import testlog_goofy
chuntseneb33f9d2017-05-12 13:38:17 +080058from cros.factory.testlog import testlog
Hung-Te Linb6287242016-05-18 14:39:05 +080059from cros.factory.tools.key_filter import KeyFilter
Wei-Han Chen78f35f62017-03-06 20:11:20 +080060from cros.factory.utils import config_utils
Hung-Te Linf707b242016-01-08 23:11:42 +080061from cros.factory.utils import debug_utils
Jon Salz2af235d2013-06-24 14:47:21 +080062from cros.factory.utils import file_utils
Joel Kitchingb85ed7f2014-10-08 18:24:39 +080063from cros.factory.utils import net_utils
Hung-Te Lin4e6357c2016-01-08 14:32:00 +080064from cros.factory.utils import process_utils
65from cros.factory.utils import sys_utils
Hung-Te Linf707b242016-01-08 23:11:42 +080066from cros.factory.utils import type_utils
Hung-Te Linf2f78f72012-02-08 19:27:11 +080067
Earl Ou6de96c02017-05-19 18:51:28 +080068from cros.factory.external import syslog
69
Hung-Te Linf2f78f72012-02-08 19:27:11 +080070
Hung-Te Linf2f78f72012-02-08 19:27:11 +080071HWID_CFG_PATH = '/usr/local/share/chromeos-hwid/cfg'
Peter Shihb4e49352017-05-25 17:35:11 +080072CACHES_DIR = os.path.join(paths.DATA_STATE_DIR, 'caches')
Hung-Te Linf2f78f72012-02-08 19:27:11 +080073
Jon Salz5c344f62012-07-13 14:31:16 +080074# Value for tests_after_shutdown that forces auto-run (e.g., after
75# a factory update, when the available set of tests might change).
76FORCE_AUTO_RUN = 'force_auto_run'
77
Wei-Han Chenc17b4112016-11-22 14:56:51 +080078# Key to load the test list iterator after shutdown test
79TESTS_AFTER_SHUTDOWN = 'tests_after_shutdown'
80
Hung-Te Linf707b242016-01-08 23:11:42 +080081Status = type_utils.Enum(['UNINITIALIZED', 'INITIALIZING', 'RUNNING',
Wei-Han Chen2ebb92d2016-01-12 14:51:41 +080082 'TERMINATING', 'TERMINATED'])
Jon Salzd7550792013-07-12 05:49:27 +080083
Jon Salz73e0fd02012-04-04 11:46:38 +080084_inited_logging = False
Hung-Te Linf2f78f72012-02-08 19:27:11 +080085
Ricky Liang45c73e72015-01-15 15:00:30 +080086
Peter Ammon1e1ec572014-06-26 17:56:32 -070087class Goofy(GoofyBase):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +080088 """The main factory flow.
Jon Salz0697cbf2012-07-04 15:14:04 +080089
90 Note that all methods in this class must be invoked from the main
91 (event) thread. Other threads, such as callbacks and TestInvocation
92 methods, should instead post events on the run queue.
93
94 TODO: Unit tests. (chrome-os-partner:7409)
95
96 Properties:
97 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).
Peter Ammon948b7172014-07-15 12:43:06 -0700118 link_manager: Instance of PresenterLinkManager for communicating
119 with GoofyPresenter
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800120 """
Ricky Liang45c73e72015-01-15 15:00:30 +0800121
Jon Salz0697cbf2012-07-04 15:14:04 +0800122 def __init__(self):
Peter Ammon1e1ec572014-06-26 17:56:32 -0700123 super(Goofy, self).__init__()
Jon Salz0697cbf2012-07-04 15:14:04 +0800124 self.uuid = str(uuid.uuid4())
125 self.state_instance = None
Earl Ouacbe99c2017-02-21 16:04:19 +0800126 self.goofy_server = None
127 self.goofy_server_thread = None
Jon Salz16d10542012-07-23 12:18:45 +0800128 self.goofy_rpc = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800129 self.event_server = None
130 self.event_server_thread = None
131 self.event_client = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800132 self.log_watcher = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800133 self.event_log = None
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800134 self.testlog = None
Earl Oua3bca122016-10-21 16:00:30 +0800135 self.plugin_controller = None
Vic Yange2c76a82014-10-30 12:48:19 -0700136 self.pytest_prespawner = None
Vic Yanga3cecf82014-12-26 00:44:21 -0800137 self._ui_initialized = False
Jon Salzc79a9982012-08-30 04:42:01 +0800138 self.dummy_shopfloor = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800139 self.invocations = {}
Jon Salz0697cbf2012-07-04 15:14:04 +0800140 self.visible_test = None
141 self.chrome = None
Jon Salz416f9cc2013-05-10 18:32:50 +0800142 self.hooks = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800143
144 self.options = None
145 self.args = None
146 self.test_list = None
Jon Salz128b0932013-07-03 16:55:26 +0800147 self.test_lists = None
Ricky Liang4bff3e32014-02-20 18:46:11 +0800148 self.run_id = None
149 self.scheduled_run_tests = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800150 self.env = None
Jon Salzb22d1172012-08-06 10:38:57 +0800151 self.last_idle = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800152 self.last_shutdown_time = None
cychiang21886742012-07-05 15:16:32 +0800153 self.last_update_check = None
Cheng-Yi Chiang194d3c02015-03-16 14:37:15 +0800154 self._suppress_periodic_update_messages = False
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +0800155 self._suppress_event_log_error_messages = False
Earl Ouab979142016-10-25 16:48:06 +0800156 self.exclusive_resources = set()
Dean Liao592e4d52013-01-10 20:06:39 +0800157 self.key_filter = None
Jon Salzd7550792013-07-12 05:49:27 +0800158 self.status = Status.UNINITIALIZED
Ricky Liang36512a32014-07-25 11:47:04 +0800159 self.ready_for_ui_connection = False
Peter Ammon1e1ec572014-06-26 17:56:32 -0700160 self.link_manager = None
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800161 self.is_restart_requested = False
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800162 self.test_list_iterator = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800163
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +0800164 self.test_list_manager = manager.Manager()
165
Hung-Te Lin6a72c642015-12-13 22:09:09 +0800166 # TODO(hungte) Support controlling remote DUT.
Hung-Te Linb6287242016-05-18 14:39:05 +0800167 self.dut = device_utils.CreateDUTInterface()
Hung-Te Lin6a72c642015-12-13 22:09:09 +0800168
Jon Salz85a39882012-07-05 16:45:04 +0800169 def test_or_root(event, parent_or_group=True):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800170 """Returns the test affected by a particular event.
Jon Salz85a39882012-07-05 16:45:04 +0800171
172 Args:
173 event: The event containing an optional 'path' attribute.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800174 parent_or_group: If True, returns the top-level parent for a test (the
Jon Salz85a39882012-07-05 16:45:04 +0800175 root node of the tests that need to be run together if the given test
176 path is to be run).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800177 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800178 try:
179 path = event.path
180 except AttributeError:
181 path = None
182
183 if path:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800184 test = self.test_list.LookupPath(path)
Jon Salz85a39882012-07-05 16:45:04 +0800185 if parent_or_group:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800186 test = test.GetTopLevelParentOrGroup()
Jon Salz85a39882012-07-05 16:45:04 +0800187 return test
Jon Salz0697cbf2012-07-04 15:14:04 +0800188 else:
Peter Shih999faf72017-07-07 11:32:42 +0800189 return self.test_list.ToFactoryTestList()
Jon Salz0697cbf2012-07-04 15:14:04 +0800190
191 self.event_handlers = {
Ricky Liang45c73e72015-01-15 15:00:30 +0800192 Event.Type.SWITCH_TEST: self.handle_switch_test,
Ricky Liang45c73e72015-01-15 15:00:30 +0800193 Event.Type.RESTART_TESTS:
194 lambda event: self.restart_tests(root=test_or_root(event)),
195 Event.Type.AUTO_RUN:
196 lambda event: self.auto_run(root=test_or_root(event)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800197 Event.Type.RUN_TESTS_WITH_STATUS:
198 lambda event: self.run_tests_with_status(
199 event.status,
200 root=test_or_root(event)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800201 Event.Type.UPDATE_SYSTEM_INFO:
202 lambda event: self.update_system_info(),
203 Event.Type.STOP:
204 lambda event: self.stop(root=test_or_root(event, False),
205 fail=getattr(event, 'fail', False),
206 reason=getattr(event, 'reason', None)),
207 Event.Type.SET_VISIBLE_TEST:
208 lambda event: self.set_visible_test(
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800209 self.test_list.LookupPath(event.path)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800210 Event.Type.CLEAR_STATE:
211 lambda event: self.clear_state(
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800212 self.test_list.LookupPath(event.path)),
Wei-Ning Huang38b75f02015-02-25 18:25:14 +0800213 Event.Type.KEY_FILTER_MODE: self.handle_key_filter_mode,
Jon Salz0697cbf2012-07-04 15:14:04 +0800214 }
215
Jon Salz0697cbf2012-07-04 15:14:04 +0800216 self.web_socket_manager = None
217
218 def destroy(self):
Ricky Liang74237a02014-09-18 15:11:23 +0800219 """Performs any shutdown tasks. Overrides base class method."""
chuntsen9d675c62017-06-20 14:35:30 +0800220 # To avoid race condition when running shutdown test.
221 for test, invoc in self.invocations.iteritems():
222 logging.info('Waiting for %s to complete...', test)
223 invoc.thread.join(3) # Timeout in 3 seconds.
224
Jon Salzd7550792013-07-12 05:49:27 +0800225 self.status = Status.TERMINATING
Jon Salz0697cbf2012-07-04 15:14:04 +0800226 if self.chrome:
227 self.chrome.kill()
228 self.chrome = None
Jon Salzc79a9982012-08-30 04:42:01 +0800229 if self.dummy_shopfloor:
230 self.dummy_shopfloor.kill()
231 self.dummy_shopfloor = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800232 if self.web_socket_manager:
233 logging.info('Stopping web sockets')
234 self.web_socket_manager.close()
235 self.web_socket_manager = None
Earl Ouacbe99c2017-02-21 16:04:19 +0800236 if self.goofy_server_thread:
237 logging.info('Stopping goofy server')
238 self.goofy_server.shutdown()
239 self.goofy_server_thread.join()
240 self.goofy_server.server_close()
241 self.goofy_server_thread = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800242 if self.state_instance:
243 self.state_instance.close()
244 if self.event_server_thread:
245 logging.info('Stopping event server')
Peter Shihce9490e2017-05-11 14:32:12 +0800246 net_utils.ShutdownTCPServer(self.event_server)
Jon Salz0697cbf2012-07-04 15:14:04 +0800247 self.event_server_thread.join()
248 self.event_server.server_close()
249 self.event_server_thread = None
250 if self.log_watcher:
251 if self.log_watcher.IsThreadStarted():
252 self.log_watcher.StopWatchThread()
253 self.log_watcher = None
Vic Yange2c76a82014-10-30 12:48:19 -0700254 if self.pytest_prespawner:
255 logging.info('Stopping pytest prespawner')
256 self.pytest_prespawner.stop()
257 self.pytest_prespawner = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800258 if self.event_client:
259 logging.info('Closing event client')
260 self.event_client.close()
261 self.event_client = None
262 if self.event_log:
263 self.event_log.Close()
264 self.event_log = None
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800265 if self.testlog:
266 self.testlog.Close()
267 self.testlog = None
Dean Liao592e4d52013-01-10 20:06:39 +0800268 if self.key_filter:
269 self.key_filter.Stop()
Peter Ammon1e1ec572014-06-26 17:56:32 -0700270 if self.link_manager:
271 self.link_manager.Stop()
272 self.link_manager = None
Earl Oua3bca122016-10-21 16:00:30 +0800273 if self.plugin_controller:
274 self.plugin_controller.StopAndDestroyAllPlugins()
275 self.plugin_controller = None
Dean Liao592e4d52013-01-10 20:06:39 +0800276
Peter Ammon1e1ec572014-06-26 17:56:32 -0700277 super(Goofy, self).destroy()
Jon Salz0697cbf2012-07-04 15:14:04 +0800278 logging.info('Done destroying Goofy')
Jon Salzd7550792013-07-12 05:49:27 +0800279 self.status = Status.TERMINATED
Jon Salz0697cbf2012-07-04 15:14:04 +0800280
Earl Ouacbe99c2017-02-21 16:04:19 +0800281 def start_goofy_server(self):
282 self.goofy_server = goofy_server.GoofyServer(
Shen-En Shihd5b96bf2017-08-09 17:47:21 +0800283 (goofy_proxy.DEFAULT_GOOFY_BIND, goofy_proxy.DEFAULT_GOOFY_PORT))
Earl Ouacbe99c2017-02-21 16:04:19 +0800284 logging.info('Starting goofy server')
285 self.goofy_server_thread = threading.Thread(
286 target=self.goofy_server.serve_forever,
287 name='GoofyServer')
288 self.goofy_server_thread.start()
289
290 # Setup static file path
291 self.goofy_server.RegisterPath(
Peter Shihad166772017-05-31 11:36:17 +0800292 '/', os.path.join(paths.FACTORY_PYTHON_PACKAGE_DIR, 'goofy/static'))
Peter Shihce03c2e2017-03-21 17:36:10 +0800293 # index.html needs to be preprocessed.
Peter Shihad166772017-05-31 11:36:17 +0800294 index_path = os.path.join(paths.FACTORY_PYTHON_PACKAGE_DIR,
Peter Shihce03c2e2017-03-21 17:36:10 +0800295 'goofy/static/index.html')
296 index_html = html_translator.TranslateHTML(file_utils.ReadFile(index_path))
297 self.goofy_server.RegisterData('/index.html', 'text/html', index_html)
Earl Ouacbe99c2017-02-21 16:04:19 +0800298
299 def init_state_instance(self):
Jon Salz2af235d2013-06-24 14:47:21 +0800300 # Before starting state server, remount stateful partitions with
301 # no commit flag. The default commit time (commit=600) makes corruption
302 # too likely.
Hung-Te Lin1968d9c2016-01-08 22:55:46 +0800303 sys_utils.ResetCommitTime()
Earl Ouacbe99c2017-02-21 16:04:19 +0800304 self.state_instance = state.FactoryState()
305 self.goofy_server.AddRPCInstance(goofy_proxy.STATE_URL, self.state_instance)
Jon Salz2af235d2013-06-24 14:47:21 +0800306
Earl Ouacbe99c2017-02-21 16:04:19 +0800307 # Setup Goofy RPC.
308 # TODO(shunhsingou): separate goofy_rpc and state server instead of
309 # injecting goofy_rpc functions into state.
Jon Salz16d10542012-07-23 12:18:45 +0800310 self.goofy_rpc = GoofyRPC(self)
311 self.goofy_rpc.RegisterMethods(self.state_instance)
Jon Salz0697cbf2012-07-04 15:14:04 +0800312
Peter Shih80e78b42017-03-10 17:00:56 +0800313 def init_i18n(self):
314 js_data = 'var goofy_i18n_data = %s;' % translation.GetAllI18nDataJS()
Peter Shihce03c2e2017-03-21 17:36:10 +0800315 self.goofy_server.RegisterData('/js/goofy-translations.js',
316 'application/javascript', js_data)
Peter Shihf65db932017-03-22 17:06:34 +0800317 self.goofy_server.RegisterData('/css/i18n.css',
318 'text/css', i18n_test_ui.GetStyleSheet())
Peter Shih80e78b42017-03-10 17:00:56 +0800319
Jon Salz0697cbf2012-07-04 15:14:04 +0800320 def start_event_server(self):
321 self.event_server = EventServer()
322 logging.info('Starting factory event server')
323 self.event_server_thread = threading.Thread(
Ricky Liang45c73e72015-01-15 15:00:30 +0800324 target=self.event_server.serve_forever,
Peter Shihfdf17682017-05-26 11:38:39 +0800325 name='EventServer')
Jon Salz0697cbf2012-07-04 15:14:04 +0800326 self.event_server_thread.start()
327
328 self.event_client = EventClient(
Ricky Liang45c73e72015-01-15 15:00:30 +0800329 callback=self.handle_event, event_loop=self.run_queue)
Jon Salz0697cbf2012-07-04 15:14:04 +0800330
331 self.web_socket_manager = WebSocketManager(self.uuid)
Earl Ouacbe99c2017-02-21 16:04:19 +0800332 self.goofy_server.AddHTTPGetHandler(
333 '/event', self.web_socket_manager.handle_web_socket)
Jon Salz0697cbf2012-07-04 15:14:04 +0800334
Jon Salz0697cbf2012-07-04 15:14:04 +0800335 def set_visible_test(self, test):
336 if self.visible_test == test:
337 return
Jon Salz2f2d42c2012-07-30 12:30:34 +0800338 if test and not test.has_ui:
339 return
Jon Salz0697cbf2012-07-04 15:14:04 +0800340
Jon Salz0697cbf2012-07-04 15:14:04 +0800341 if self.visible_test:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800342 self.visible_test.UpdateState(visible=False)
Peter Shihd87297f2017-08-21 15:43:13 +0800343 if test:
344 test.UpdateState(visible=True)
Jon Salz0697cbf2012-07-04 15:14:04 +0800345 self.visible_test = test
346
Ricky Liang48e47f92014-02-26 19:31:51 +0800347 def shutdown(self, operation):
348 """Starts shutdown procedure.
349
350 Args:
Vic (Chun-Ju) Yang05b0d952014-04-28 17:39:09 +0800351 operation: The shutdown operation (reboot, full_reboot, or halt).
Ricky Liang48e47f92014-02-26 19:31:51 +0800352 """
353 active_tests = []
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800354 for test in self.test_list.Walk():
355 if not test.IsLeaf():
Ricky Liang48e47f92014-02-26 19:31:51 +0800356 continue
357
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800358 test_state = test.GetState()
Ricky Liang48e47f92014-02-26 19:31:51 +0800359 if test_state.status == TestState.ACTIVE:
360 active_tests.append(test)
361
Ricky Liang48e47f92014-02-26 19:31:51 +0800362 if not (len(active_tests) == 1 and
363 isinstance(active_tests[0], factory.ShutdownStep)):
364 logging.error(
365 'Calling Goofy shutdown outside of the shutdown factory test')
366 return
367
368 logging.info('Start Goofy shutdown (%s)', operation)
369 # Save pending test list in the state server
370 self.state_instance.set_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800371 TESTS_AFTER_SHUTDOWN, self.test_list_iterator)
Ricky Liang48e47f92014-02-26 19:31:51 +0800372 # Save shutdown time
373 self.state_instance.set_shared_data('shutdown_time', time.time())
374
375 with self.env.lock:
376 self.event_log.Log('shutdown', operation=operation)
377 shutdown_result = self.env.shutdown(operation)
378 if shutdown_result:
379 # That's all, folks!
Peter Ammon1e1ec572014-06-26 17:56:32 -0700380 self.run_enqueue(None)
Ricky Liang48e47f92014-02-26 19:31:51 +0800381 else:
382 # Just pass (e.g., in the chroot).
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800383 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, None)
Ricky Liang48e47f92014-02-26 19:31:51 +0800384 # Send event with no fields to indicate that there is no
385 # longer a pending shutdown.
386 self.event_client.post_event(Event(Event.Type.PENDING_SHUTDOWN))
387
388 def handle_shutdown_complete(self, test):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800389 """Handles the case where a shutdown was detected during a shutdown step.
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800390
Ricky Liang6fe218c2013-12-27 15:17:17 +0800391 Args:
392 test: The ShutdownStep.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800393 """
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800394 test_state = test.UpdateState(increment_shutdown_count=1)
Jon Salz0697cbf2012-07-04 15:14:04 +0800395 logging.info('Detected shutdown (%d of %d)',
Ricky Liang48e47f92014-02-26 19:31:51 +0800396 test_state.shutdown_count, test.iterations)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800397
Ricky Liang48e47f92014-02-26 19:31:51 +0800398 tests_after_shutdown = self.state_instance.get_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800399 TESTS_AFTER_SHUTDOWN, optional=True)
400
401 # Make this shutdown test the next test to run. This is to continue on
402 # post-shutdown verification in the shutdown step.
Ricky Liang48e47f92014-02-26 19:31:51 +0800403 if not tests_after_shutdown:
Wei-Han Chen29663c12017-06-27 10:28:54 +0800404 goofy_error = 'TESTS_AFTER_SHTUDOWN is not set'
Ricky Liang48e47f92014-02-26 19:31:51 +0800405 self.state_instance.set_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800406 TESTS_AFTER_SHUTDOWN, TestListIterator(test))
407 else:
Wei-Han Chen29663c12017-06-27 10:28:54 +0800408 goofy_error = tests_after_shutdown.RestartLastTest()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800409 self.state_instance.set_shared_data(
410 TESTS_AFTER_SHUTDOWN, tests_after_shutdown)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800411
Ricky Liang48e47f92014-02-26 19:31:51 +0800412 # Set 'post_shutdown' to inform shutdown test that a shutdown just occurred.
Ricky Liangb7eb8772014-09-15 18:05:22 +0800413 self.state_instance.set_shared_data(
Wei-Han Chen29663c12017-06-27 10:28:54 +0800414 state.KEY_POST_SHUTDOWN % test.path,
415 {'invocation': self.state_instance.get_test_state(test.path).invocation,
416 'goofy_error': goofy_error})
Jon Salz258a40c2012-04-19 12:34:01 +0800417
Jon Salz0697cbf2012-07-04 15:14:04 +0800418 def init_states(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800419 """Initializes all states on startup."""
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800420 for test in self.test_list.GetAllTests():
Jon Salz0697cbf2012-07-04 15:14:04 +0800421 # Make sure the state server knows about all the tests,
422 # defaulting to an untested state.
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800423 test.UpdateState(update_parent=False, visible=False)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800424
Earl Ouf76e55c2017-03-07 11:48:34 +0800425 is_unexpected_shutdown = False
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800426
Jon Salz0697cbf2012-07-04 15:14:04 +0800427 # Any 'active' tests should be marked as failed now.
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800428 for test in self.test_list.Walk():
429 if not test.IsLeaf():
Jon Salza6711d72012-07-18 14:33:03 +0800430 # Don't bother with parents; they will be updated when their
431 # children are updated.
432 continue
433
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800434 test_state = test.GetState()
Jon Salz0697cbf2012-07-04 15:14:04 +0800435 if test_state.status != TestState.ACTIVE:
436 continue
437 if isinstance(test, factory.ShutdownStep):
438 # Shutdown while the test was active - that's good.
Ricky Liang48e47f92014-02-26 19:31:51 +0800439 self.handle_shutdown_complete(test)
Jon Salz0697cbf2012-07-04 15:14:04 +0800440 else:
Earl Ouf76e55c2017-03-07 11:48:34 +0800441 is_unexpected_shutdown = True
Jon Salz0697cbf2012-07-04 15:14:04 +0800442 error_msg = 'Unexpected shutdown while test was running'
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800443 # TODO(itspeter): Add testlog to collect expired session infos.
Jon Salz0697cbf2012-07-04 15:14:04 +0800444 self.event_log.Log('end_test',
Ricky Liang45c73e72015-01-15 15:00:30 +0800445 path=test.path,
446 status=TestState.FAILED,
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800447 invocation=test.GetState().invocation,
Earl Ouf76e55c2017-03-07 11:48:34 +0800448 error_msg=error_msg)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800449 test.UpdateState(
Ricky Liang45c73e72015-01-15 15:00:30 +0800450 status=TestState.FAILED,
451 error_msg=error_msg)
Chun-Ta Lin87c2dac2015-05-02 01:35:01 -0700452 # Trigger the OnTestFailure callback.
Claire Changd1961a22015-08-05 16:15:55 +0800453 self.run_queue.put(lambda: self.test_fail(test))
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800454
Jon Salz50efe942012-07-26 11:54:10 +0800455 if not test.never_fails:
456 # For "never_fails" tests (such as "Start"), don't cancel
457 # pending tests, since reboot is expected.
458 factory.console.info('Unexpected shutdown while test %s '
459 'running; cancelling any pending tests',
460 test.path)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800461 # cancel pending tests by replace the iterator with an empty one
462 self.state_instance.set_shared_data(
463 TESTS_AFTER_SHUTDOWN,
464 TestListIterator(None))
Jon Salz008f4ea2012-08-28 05:39:45 +0800465
Earl Ouf76e55c2017-03-07 11:48:34 +0800466 if is_unexpected_shutdown:
467 logging.warning("Unexpected shutdown.")
468 self.dut.hooks.OnUnexpectedReboot()
469
Wei-Han Chen109d76f2017-08-08 18:50:35 +0800470 if self.test_list.options.read_device_data_from_vpd_on_init:
471 vpd_data = {}
472 for section in [device_data.NAME_RO, device_data.NAME_RW]:
473 try:
474 vpd_data[section] = self.dut.vpd.boot.GetPartition(section).GetAll()
475 except Exception:
476 logging.exception('Failed to read %s_VPD, ignored...',
477 section.upper())
478 # using None for key_map will use default key_map
479 device_data.UpdateDeviceDataFromVPD(None, vpd_data)
480
Wei-Han Chen212d2af2017-08-03 18:12:23 +0800481 # state_instance is initialized, we can mark skipped and waived tests now.
482 self.test_list.SetSkippedAndWaivedTests()
483
Jon Salz0697cbf2012-07-04 15:14:04 +0800484 def handle_event(self, event):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800485 """Handles an event from the event server."""
Jon Salz0697cbf2012-07-04 15:14:04 +0800486 handler = self.event_handlers.get(event.type)
487 if handler:
488 handler(event)
489 else:
490 # We don't register handlers for all event types - just ignore
491 # this event.
492 logging.debug('Unbound event type %s', event.type)
Jon Salz4f6c7172012-06-11 20:45:36 +0800493
Vic Yangaabf9fd2013-04-09 18:56:13 +0800494 def check_critical_factory_note(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800495 """Returns True if the last factory note is critical."""
Vic Yangaabf9fd2013-04-09 18:56:13 +0800496 notes = self.state_instance.get_shared_data('factory_note', True)
497 return notes and notes[-1]['level'] == 'CRITICAL'
498
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800499 def schedule_restart(self):
500 """Schedules a restart event when any invocation is completed."""
501 self.is_restart_requested = True
502
503 def invocation_completion(self):
504 """Callback when an invocation is completed."""
505 if self.is_restart_requested:
506 logging.info('Restart by scheduled event.')
507 self.is_restart_requested = False
508 self.restart_tests()
509 else:
510 self.run_next_test()
511
Jon Salz0697cbf2012-07-04 15:14:04 +0800512 def run_next_test(self):
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800513 """Runs the next eligible test.
henryhsu4cc6b022014-04-22 17:12:42 +0800514
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800515 self.test_list_iterator (a TestListIterator object) will determine which
516 test should be run.
henryhsu4cc6b022014-04-22 17:12:42 +0800517 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800518 self.reap_completed_tests()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800519
520 if self.invocations:
521 # there are tests still running, we cannot start new tests
Vic Yangaabf9fd2013-04-09 18:56:13 +0800522 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800523
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800524 if self.check_critical_factory_note():
525 logging.info('has critical factory note, stop running')
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800526 self.test_list_iterator.Stop()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800527 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800528
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800529 while True:
530 try:
531 path = self.test_list_iterator.next()
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800532 test = self.test_list.LookupPath(path)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800533 except StopIteration:
534 logging.info('no next test, stop running')
Jon Salz0697cbf2012-07-04 15:14:04 +0800535 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800536
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800537 # check if we have run all required tests
Jon Salz304a75d2012-07-06 11:14:15 +0800538 untested = set()
Jon Salza1412922012-07-23 16:04:17 +0800539 for requirement in test.require_run:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800540 for i in requirement.test.Walk():
Jon Salza1412922012-07-23 16:04:17 +0800541 if i == test:
Jon Salz304a75d2012-07-06 11:14:15 +0800542 # We've hit this test itself; stop checking
543 break
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800544 if ((i.GetState().status == TestState.UNTESTED) or
Wei-Han Chen3a160172017-07-11 17:31:28 +0800545 (requirement.passed and
546 i.GetState().status not in [TestState.SKIPPED,
547 TestState.PASSED])):
Jon Salz304a75d2012-07-06 11:14:15 +0800548 # Found an untested test; move on to the next
549 # element in require_run.
Jon Salza1412922012-07-23 16:04:17 +0800550 untested.add(i)
Jon Salz304a75d2012-07-06 11:14:15 +0800551 break
552
553 if untested:
554 untested_paths = ', '.join(sorted([x.path for x in untested]))
555 if self.state_instance.get_shared_data('engineering_mode',
556 optional=True):
557 # In engineering mode, we'll let it go.
558 factory.console.warn('In engineering mode; running '
559 '%s even though required tests '
560 '[%s] have not completed',
561 test.path, untested_paths)
562 else:
563 # Not in engineering mode; mark it failed.
564 error_msg = ('Required tests [%s] have not been run yet'
565 % untested_paths)
566 factory.console.error('Not running %s: %s',
567 test.path, error_msg)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800568 test.UpdateState(status=TestState.FAILED,
569 error_msg=error_msg)
Jon Salz304a75d2012-07-06 11:14:15 +0800570 continue
571
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800572 # okay, let's run the test
Ricky Liang48e47f92014-02-26 19:31:51 +0800573 if (isinstance(test, factory.ShutdownStep) and
Ricky Liangb7eb8772014-09-15 18:05:22 +0800574 self.state_instance.get_shared_data(
Wei-Han Chen29663c12017-06-27 10:28:54 +0800575 state.KEY_POST_SHUTDOWN % test.path, optional=True)):
Ricky Liang48e47f92014-02-26 19:31:51 +0800576 # Invoking post shutdown method of shutdown test. We should retain the
577 # iterations_left and retries_left of the original test state.
578 test_state = self.state_instance.get_test_state(test.path)
579 self._run_test(test, test_state.iterations_left,
580 test_state.retries_left)
581 else:
582 # Starts a new test run; reset iterations and retries.
583 self._run_test(test, test.iterations, test.retries)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800584 return # to leave while
Jon Salz1acc8742012-07-17 17:45:55 +0800585
Cheng-Yi Chiangce05c002013-04-04 02:13:17 +0800586 def _run_test(self, test, iterations_left=None, retries_left=None):
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800587 """Invokes the test.
588
589 The argument `test` should be either a leaf test (no subtests) or a parallel
590 test (all subtests should be run in parallel).
591 """
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800592 if not self._ui_initialized and not test.IsNoHost():
Vic Yanga3cecf82014-12-26 00:44:21 -0800593 self.init_ui()
Jon Salz1acc8742012-07-17 17:45:55 +0800594
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800595 if test.IsLeaf():
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800596 invoc = TestInvocation(
597 self, test, on_completion=self.invocation_completion,
598 on_test_failure=lambda: self.test_fail(test))
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800599 new_state = test.UpdateState(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800600 status=TestState.ACTIVE, increment_count=1, error_msg='',
601 invocation=invoc.uuid, iterations_left=iterations_left,
602 retries_left=retries_left,
603 visible=(self.visible_test == test))
604 invoc.count = new_state.count
605 self.invocations[test] = invoc
606 if self.visible_test is None and test.has_ui:
607 self.set_visible_test(test)
608 self.check_plugins()
609 invoc.start()
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800610 elif test.parallel:
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800611 for subtest in test.subtests:
612 # TODO(stimim): what if the subtests *must* be run in parallel?
613 # for example, stressapptest and countdown test.
614
615 # Make sure we don't need to skip it:
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800616 if not self.test_list_iterator.CheckSkip(subtest):
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800617 self._run_test(subtest, subtest.iterations, subtest.retries)
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800618 else:
619 # This should never happen, there must be something wrong.
620 # However, we can't raise an exception, otherwise goofy will be closed
621 logging.critical(
622 'Goofy should not get a non-leaf test that is not parallel: %r',
623 test)
624 factory.console.critical(
625 'Goofy should not get a non-leaf test that is not parallel: %r',
626 test)
Jon Salz5f2a0672012-05-22 17:14:06 +0800627
Earl Oua3bca122016-10-21 16:00:30 +0800628 def check_plugins(self):
629 """Check plugins to be paused or resumed."""
630 exclusive_resources = set()
631 for test in self.invocations:
632 exclusive_resources = exclusive_resources.union(
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800633 test.GetExclusiveResources())
Earl Oua3bca122016-10-21 16:00:30 +0800634 self.plugin_controller.PauseAndResumePluginByResource(exclusive_resources)
635
cychiang21886742012-07-05 15:16:32 +0800636 def check_for_updates(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800637 """Schedules an asynchronous check for updates if necessary."""
cychiang21886742012-07-05 15:16:32 +0800638 if not self.test_list.options.update_period_secs:
639 # Not enabled.
640 return
641
642 now = time.time()
643 if self.last_update_check and (
644 now - self.last_update_check <
645 self.test_list.options.update_period_secs):
646 # Not yet time for another check.
647 return
648
649 self.last_update_check = now
650
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800651 def handle_check_for_update(
652 reached_shopfloor, toolkit_version, needs_update):
cychiang21886742012-07-05 15:16:32 +0800653 if reached_shopfloor:
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800654 new_update_toolkit_version = toolkit_version if needs_update else None
655 if self.dut.info.update_toolkit_version != new_update_toolkit_version:
656 logging.info('Received new update TOOLKIT_VERSION: %s',
657 new_update_toolkit_version)
658 self.dut.info.Overrides('update_toolkit_version',
659 new_update_toolkit_version)
Peter Ammon1e1ec572014-06-26 17:56:32 -0700660 self.run_enqueue(self.update_system_info)
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800661 elif not self._suppress_periodic_update_messages:
662 logging.warning('Suppress error messages for periodic update checking '
663 'after the first one.')
664 self._suppress_periodic_update_messages = True
cychiang21886742012-07-05 15:16:32 +0800665
666 updater.CheckForUpdateAsync(
Ricky Liang45c73e72015-01-15 15:00:30 +0800667 handle_check_for_update,
Cheng-Yi Chiang194d3c02015-03-16 14:37:15 +0800668 self.test_list.options.shopfloor_timeout_secs,
669 self._suppress_periodic_update_messages)
cychiang21886742012-07-05 15:16:32 +0800670
Jon Salza6711d72012-07-18 14:33:03 +0800671 def cancel_pending_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800672 """Cancels any tests in the run queue."""
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800673 self.run_tests(None)
Jon Salza6711d72012-07-18 14:33:03 +0800674
Ricky Liang4bff3e32014-02-20 18:46:11 +0800675 def restore_active_run_state(self):
676 """Restores active run id and the list of scheduled tests."""
677 self.run_id = self.state_instance.get_shared_data('run_id', optional=True)
678 self.scheduled_run_tests = self.state_instance.get_shared_data(
679 'scheduled_run_tests', optional=True)
680
681 def set_active_run_state(self):
682 """Sets active run id and the list of scheduled tests."""
683 self.run_id = str(uuid.uuid4())
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800684 # try our best to predict which tests will be run.
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800685 self.scheduled_run_tests = self.test_list_iterator.GetPendingTests()
Ricky Liang4bff3e32014-02-20 18:46:11 +0800686 self.state_instance.set_shared_data('run_id', self.run_id)
687 self.state_instance.set_shared_data('scheduled_run_tests',
688 self.scheduled_run_tests)
689
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800690 def run_tests(self, subtree, status_filter=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800691 """Runs tests under subtree.
Jon Salz258a40c2012-04-19 12:34:01 +0800692
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800693 Run tests under a given subtree.
Jon Salzb1b39092012-05-03 02:05:09 +0800694
Ricky Liang6fe218c2013-12-27 15:17:17 +0800695 Args:
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800696 subtree: root of subtree to run or None to run nothing.
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +0800697 status_filter: List of available test states. Only run the tests which
698 states are in the list. Set to None if all test states are available.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800699 """
Hung-Te Lin410f70a2015-12-15 14:53:42 +0800700 self.dut.hooks.OnTestStart()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800701 self.test_list_iterator = TestListIterator(
702 subtree, status_filter, self.test_list)
703 if subtree is not None:
Ricky Liang4bff3e32014-02-20 18:46:11 +0800704 self.set_active_run_state()
Jon Salz0697cbf2012-07-04 15:14:04 +0800705 self.run_next_test()
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800706
Jon Salz0697cbf2012-07-04 15:14:04 +0800707 def reap_completed_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800708 """Removes completed tests from the set of active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +0800709
710 Also updates the visible test if it was reaped.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800711 """
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800712 test_completed = False
Jon Salz0697cbf2012-07-04 15:14:04 +0800713 for t, v in dict(self.invocations).iteritems():
714 if v.is_completed():
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800715 test_completed = True
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800716 new_state = t.UpdateState(**v.update_state_on_completion)
Jon Salz0697cbf2012-07-04 15:14:04 +0800717 del self.invocations[t]
718
Johny Lin62ed2a32015-05-13 11:57:12 +0800719 # Stop on failure if flag is true and there is no retry chances.
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800720 if (self.test_list.options.stop_on_failure and
Johny Lin62ed2a32015-05-13 11:57:12 +0800721 new_state.retries_left < 0 and
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800722 new_state.status == TestState.FAILED):
723 # Clean all the tests to cause goofy to stop.
Ricky Liang45c73e72015-01-15 15:00:30 +0800724 factory.console.info('Stop on failure triggered. Empty the queue.')
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800725 self.cancel_pending_tests()
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800726
Jon Salz1acc8742012-07-17 17:45:55 +0800727 if new_state.iterations_left and new_state.status == TestState.PASSED:
728 # Play it again, Sam!
729 self._run_test(t)
Cheng-Yi Chiangce05c002013-04-04 02:13:17 +0800730 # new_state.retries_left is obtained after update.
731 # For retries_left == 0, test can still be run for the last time.
732 elif (new_state.retries_left >= 0 and
733 new_state.status == TestState.FAILED):
734 # Still have to retry, Sam!
735 self._run_test(t)
Jon Salz1acc8742012-07-17 17:45:55 +0800736
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800737 if test_completed:
Vic Yangf01c59f2013-04-19 17:37:56 +0800738 self.log_watcher.KickWatchThread()
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800739
Jon Salz0697cbf2012-07-04 15:14:04 +0800740 if (self.visible_test is None or
Jon Salz85a39882012-07-05 16:45:04 +0800741 self.visible_test not in self.invocations):
Jon Salz0697cbf2012-07-04 15:14:04 +0800742 self.set_visible_test(None)
743 # Make the first running test, if any, the visible test
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800744 for t in self.test_list.Walk():
Jon Salz0697cbf2012-07-04 15:14:04 +0800745 if t in self.invocations:
746 self.set_visible_test(t)
747 break
748
Jon Salz6dc031d2013-06-19 13:06:23 +0800749 def kill_active_tests(self, abort, root=None, reason=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800750 """Kills and waits for all active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +0800751
Jon Salz85a39882012-07-05 16:45:04 +0800752 Args:
753 abort: True to change state of killed tests to FAILED, False for
Jon Salz0697cbf2012-07-04 15:14:04 +0800754 UNTESTED.
Jon Salz85a39882012-07-05 16:45:04 +0800755 root: If set, only kills tests with root as an ancestor.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800756 reason: If set, the abort reason.
757 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800758 self.reap_completed_tests()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800759 # since we remove objects while iterating, make a copy
760 for test, invoc in dict(self.invocations).iteritems():
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800761 if root and not test.HasAncestor(root):
Jon Salz85a39882012-07-05 16:45:04 +0800762 continue
763
Ricky Liang45c73e72015-01-15 15:00:30 +0800764 factory.console.info('Killing active test %s...', test.path)
Jon Salz6dc031d2013-06-19 13:06:23 +0800765 invoc.abort_and_join(reason)
Ricky Liang45c73e72015-01-15 15:00:30 +0800766 factory.console.info('Killed %s', test.path)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800767 test.UpdateState(**invoc.update_state_on_completion)
Jon Salz0697cbf2012-07-04 15:14:04 +0800768 del self.invocations[test]
Jon Salz1acc8742012-07-17 17:45:55 +0800769
Jon Salz0697cbf2012-07-04 15:14:04 +0800770 if not abort:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800771 test.UpdateState(status=TestState.UNTESTED)
Jon Salz0697cbf2012-07-04 15:14:04 +0800772 self.reap_completed_tests()
773
Jon Salz6dc031d2013-06-19 13:06:23 +0800774 def stop(self, root=None, fail=False, reason=None):
775 self.kill_active_tests(fail, root, reason)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800776
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800777 self.test_list_iterator.Stop(root)
Jon Salz85a39882012-07-05 16:45:04 +0800778 self.run_next_test()
Jon Salz0697cbf2012-07-04 15:14:04 +0800779
Jon Salz4712ac72013-02-07 17:12:05 +0800780 def clear_state(self, root=None):
Jon Salzd7550792013-07-12 05:49:27 +0800781 if root is None:
782 root = self.test_list
Jon Salz6dc031d2013-06-19 13:06:23 +0800783 self.stop(root, reason='Clearing test state')
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800784 for f in root.Walk():
785 if f.IsLeaf():
786 f.UpdateState(status=TestState.UNTESTED)
Jon Salz4712ac72013-02-07 17:12:05 +0800787
Jon Salz6dc031d2013-06-19 13:06:23 +0800788 def abort_active_tests(self, reason=None):
789 self.kill_active_tests(True, reason=reason)
Jon Salz0697cbf2012-07-04 15:14:04 +0800790
791 def main(self):
Jon Salzeff94182013-06-19 15:06:28 +0800792 syslog.openlog('goofy')
793
Jon Salz0697cbf2012-07-04 15:14:04 +0800794 try:
Jon Salzd7550792013-07-12 05:49:27 +0800795 self.status = Status.INITIALIZING
Jon Salz0697cbf2012-07-04 15:14:04 +0800796 self.init()
797 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +0800798 success=True)
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800799 testlog.Log(
Joel Kitching9eb203a2016-04-21 15:36:30 +0800800 testlog.StationInit({
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800801 'stationDeviceId': testlog_goofy.GetDeviceID(),
Joel Kitching21bc69b2016-07-13 08:29:52 -0700802 'stationInstallationId': testlog_goofy.GetInstallationID(),
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800803 'count': testlog_goofy.GetInitCount(),
Joel Kitching9eb203a2016-04-21 15:36:30 +0800804 'success': True}))
Hung-Te Linc8174b52017-06-02 11:11:45 +0800805 except Exception:
Joel Kitching9eb203a2016-04-21 15:36:30 +0800806 try:
807 if self.event_log:
Jon Salz0697cbf2012-07-04 15:14:04 +0800808 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +0800809 success=False,
810 trace=traceback.format_exc())
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800811 if self.testlog:
812 testlog.Log(
Joel Kitching9eb203a2016-04-21 15:36:30 +0800813 testlog.StationInit({
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800814 'stationDeviceId': testlog_goofy.GetDeviceID(),
Joel Kitching21bc69b2016-07-13 08:29:52 -0700815 'stationInstallationId': testlog_goofy.GetInstallationID(),
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800816 'count': testlog_goofy.GetInitCount(),
Joel Kitching9eb203a2016-04-21 15:36:30 +0800817 'success': False,
818 'failureMessage': traceback.format_exc()}))
Hung-Te Linc8174b52017-06-02 11:11:45 +0800819 except Exception:
Joel Kitching9eb203a2016-04-21 15:36:30 +0800820 pass
Jon Salz0697cbf2012-07-04 15:14:04 +0800821 raise
822
Jon Salzd7550792013-07-12 05:49:27 +0800823 self.status = Status.RUNNING
Jon Salzeff94182013-06-19 15:06:28 +0800824 syslog.syslog('Goofy (factory test harness) starting')
Chun-Ta Lin5d12b592015-06-30 00:54:23 -0700825 syslog.syslog('Boot sequence = %d' % GetBootSequence())
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800826 syslog.syslog('Goofy init count = %d' % testlog_goofy.GetInitCount())
Jon Salz0697cbf2012-07-04 15:14:04 +0800827 self.run()
828
829 def update_system_info(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800830 """Updates system info."""
Shen-En Shihce8ffe02017-08-01 18:58:09 +0800831 logging.info('Received a notify to update system info.')
832 self.dut.info.Invalidate()
833
834 # Propagate this notify to goofy components
835 try:
836 status_monitor = plugin_controller.GetPluginRPCProxy(
837 'status_monitor.status_monitor')
838 status_monitor.UpdateDeviceInfo()
839 except Exception:
840 logging.debug('Failed to update status monitor plugin.')
Jon Salz0697cbf2012-07-04 15:14:04 +0800841
Jon Salzeb42f0d2012-07-27 19:14:04 +0800842 def update_factory(self, auto_run_on_restart=False, post_update_hook=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800843 """Commences updating factory software.
Jon Salzeb42f0d2012-07-27 19:14:04 +0800844
845 Args:
846 auto_run_on_restart: Auto-run when the machine comes back up.
847 post_update_hook: Code to call after update but immediately before
848 restart.
849
850 Returns:
851 Never if the update was successful (we just reboot).
852 False if the update was unnecessary (no update available).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800853 """
Jon Salz6dc031d2013-06-19 13:06:23 +0800854 self.kill_active_tests(False, reason='Factory software update')
Jon Salza6711d72012-07-18 14:33:03 +0800855 self.cancel_pending_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +0800856
Jon Salz5c344f62012-07-13 14:31:16 +0800857 def pre_update_hook():
858 if auto_run_on_restart:
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800859 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN,
Jon Salz5c344f62012-07-13 14:31:16 +0800860 FORCE_AUTO_RUN)
861 self.state_instance.close()
862
Jon Salzeb42f0d2012-07-27 19:14:04 +0800863 if updater.TryUpdate(pre_update_hook=pre_update_hook):
864 if post_update_hook:
865 post_update_hook()
866 self.env.shutdown('reboot')
Jon Salz0697cbf2012-07-04 15:14:04 +0800867
chuntsen9d675c62017-06-20 14:35:30 +0800868 def handle_signal(self, signum, unused_frame):
869 names = [signame for signame in dir(signal) if signame.startswith('SIG') and
870 getattr(signal, signame) == signum]
871 signal_name = ', '.join(names) if names else 'UNKNOWN'
872 logging.error('Received signal %s(%d)', signal_name, signum)
Peter Ammon1e1ec572014-06-26 17:56:32 -0700873 self.run_enqueue(None)
Jon Salz77c151e2012-08-28 07:20:37 +0800874 raise KeyboardInterrupt()
875
Jon Salz128b0932013-07-03 16:55:26 +0800876 def GetTestList(self, test_list_id):
877 """Returns the test list with the given ID.
878
879 Raises:
880 TestListError: The test list ID is not valid.
881 """
882 try:
883 return self.test_lists[test_list_id]
884 except KeyError:
885 raise test_lists.TestListError(
886 '%r is not a valid test list ID (available IDs are [%s])' % (
887 test_list_id, ', '.join(sorted(self.test_lists.keys()))))
888
Chih-Yu Huang1725d622017-03-24 16:08:35 +0800889 def _RecordStartError(self, error_message):
890 """Appends the startup error message into the shared data."""
891 KEY = 'startup_error'
892 data = self.state_instance.get_shared_data(KEY, optional=True)
893 new_data = '%s\n\n%s' % (data, error_message) if data else error_message
894 self.state_instance.set_shared_data(KEY, new_data)
895
Jon Salz128b0932013-07-03 16:55:26 +0800896 def InitTestLists(self):
Joel Kitching50a63ea2016-02-22 13:15:09 +0800897 """Reads in all test lists and sets the active test list.
898
899 Returns:
900 True if the active test list could be set, False if failed.
901 """
902 startup_errors = []
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +0800903
904 self.test_lists, failed_files = self.test_list_manager.BuildAllTestLists()
905
Jon Salzd7550792013-07-12 05:49:27 +0800906 logging.info('Loaded test lists: [%s]',
907 test_lists.DescribeTestLists(self.test_lists))
Jon Salz128b0932013-07-03 16:55:26 +0800908
Joel Kitching50a63ea2016-02-22 13:15:09 +0800909 # Check for any syntax errors in test list files.
910 if failed_files:
911 logging.info('Failed test list files: [%s]',
912 ' '.join(failed_files.keys()))
913 for f, exc_info in failed_files.iteritems():
914 logging.error('Error in test list file: %s', f,
915 exc_info=exc_info)
916
917 # Limit the stack trace to the very last entry.
918 exc_type, exc_value, exc_traceback = exc_info
919 while exc_traceback and exc_traceback.tb_next:
920 exc_traceback = exc_traceback.tb_next
921
922 exc_string = ''.join(
923 traceback.format_exception(
924 exc_type, exc_value, exc_traceback)).rstrip()
925 startup_errors.append('Error in test list file (%s):\n%s'
926 % (f, exc_string))
927
Jon Salz128b0932013-07-03 16:55:26 +0800928 if not self.options.test_list:
929 self.options.test_list = test_lists.GetActiveTestListId()
930
Joel Kitching50a63ea2016-02-22 13:15:09 +0800931 # Check for a non-existent test list ID.
932 try:
Wei-Han Chen84fee7c2016-08-26 21:56:25 +0800933 self.test_list = self.GetTestList(self.options.test_list)
Joel Kitching50a63ea2016-02-22 13:15:09 +0800934 logging.info('Active test list: %s', self.test_list.test_list_id)
935 except test_lists.TestListError as e:
936 logging.exception('Invalid active test list: %s',
937 self.options.test_list)
938 startup_errors.append(e.message)
Jon Salz128b0932013-07-03 16:55:26 +0800939
Joel Kitching50a63ea2016-02-22 13:15:09 +0800940 # We may have failed loading the active test list.
941 if self.test_list:
Joel Kitching50a63ea2016-02-22 13:15:09 +0800942 self.test_list.state_instance = self.state_instance
Jon Salz128b0932013-07-03 16:55:26 +0800943
Joel Kitching50a63ea2016-02-22 13:15:09 +0800944 # Show all startup errors.
945 if startup_errors:
Chih-Yu Huang1725d622017-03-24 16:08:35 +0800946 self._RecordStartError('\n\n'.join(startup_errors))
Joel Kitching50a63ea2016-02-22 13:15:09 +0800947
948 # Only return False if failed to load the active test list.
949 return bool(self.test_list)
Jon Salz128b0932013-07-03 16:55:26 +0800950
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +0800951 def init_hooks(self):
952 """Initializes hooks.
953
954 Must run after self.test_list ready.
955 """
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +0800956 module, cls = self.test_list.options.hooks_class.rsplit('.', 1)
957 self.hooks = getattr(__import__(module, fromlist=[cls]), cls)()
958 assert isinstance(self.hooks, factory.Hooks), (
Ricky Liang45c73e72015-01-15 15:00:30 +0800959 'hooks should be of type Hooks but is %r' % type(self.hooks))
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +0800960 self.hooks.test_list = self.test_list
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +0800961 self.hooks.OnCreatedTestList()
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +0800962
Vic Yanga3cecf82014-12-26 00:44:21 -0800963 def init_ui(self):
964 """Initialize UI."""
965 self._ui_initialized = True
966 if self.options.ui == 'chrome':
Vic Yanga3cecf82014-12-26 00:44:21 -0800967 logging.info('Waiting for a web socket connection')
968 self.web_socket_manager.wait()
969
Jon Salz0697cbf2012-07-04 15:14:04 +0800970 def init(self, args=None, env=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800971 """Initializes Goofy.
Jon Salz0697cbf2012-07-04 15:14:04 +0800972
973 Args:
974 args: A list of command-line arguments. Uses sys.argv if
975 args is None.
976 env: An Environment instance to use (or None to choose
977 FakeChrootEnvironment or DUTEnvironment as appropriate).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800978 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800979 parser = OptionParser()
980 parser.add_option('-v', '--verbose', dest='verbose',
Jon Salz8fa8e832012-07-13 19:04:09 +0800981 action='store_true',
982 help='Enable debug logging')
Jon Salz0697cbf2012-07-04 15:14:04 +0800983 parser.add_option('--print_test_list', dest='print_test_list',
Wei-Han Chen84fee7c2016-08-26 21:56:25 +0800984 metavar='TEST_LIST_ID',
985 help='Print the content of TEST_LIST_ID and exit')
Jon Salz0697cbf2012-07-04 15:14:04 +0800986 parser.add_option('--restart', dest='restart',
Jon Salz8fa8e832012-07-13 19:04:09 +0800987 action='store_true',
988 help='Clear all test state')
Jon Salz0697cbf2012-07-04 15:14:04 +0800989 parser.add_option('--ui', dest='ui', type='choice',
Jon Salz7b5482e2014-08-04 17:48:41 +0800990 choices=['none', 'chrome'],
Jon Salz2f881df2013-02-01 17:00:35 +0800991 default='chrome',
Jon Salz8fa8e832012-07-13 19:04:09 +0800992 help='UI to use')
Jon Salz0697cbf2012-07-04 15:14:04 +0800993 parser.add_option('--test_list', dest='test_list',
Wei-Han Chen84fee7c2016-08-26 21:56:25 +0800994 metavar='TEST_LIST_ID',
995 help='Use test list whose id is TEST_LIST_ID')
Jon Salzc79a9982012-08-30 04:42:01 +0800996 parser.add_option('--dummy_shopfloor', action='store_true',
997 help='Use a dummy shopfloor server')
Ricky Liang6fe218c2013-12-27 15:17:17 +0800998 parser.add_option('--automation-mode',
999 choices=[m.lower() for m in AutomationMode],
Ricky Liang45c73e72015-01-15 15:00:30 +08001000 default='none', help='Factory test automation mode.')
Ricky Liang117484a2014-04-14 11:14:41 +08001001 parser.add_option('--no-auto-run-on-start', dest='auto_run_on_start',
1002 action='store_false', default=True,
1003 help=('do not automatically run the test list on goofy '
1004 'start; this is only valid when factory test '
1005 'automation is enabled'))
Chun-Ta Lina8dd3172014-11-26 16:15:13 +08001006 parser.add_option('--handshake_timeout', dest='handshake_timeout',
1007 type='float', default=0.3,
1008 help=('RPC timeout when doing handshake between device '
1009 'and presenter.'))
Vic Yang7d693c42014-09-14 09:52:39 +08001010 parser.add_option('--standalone', dest='standalone',
1011 action='store_true', default=False,
1012 help=('Assume the presenter is running on the same '
1013 'machines.'))
Hung-Te Lin8f6a3782015-01-06 22:58:32 +08001014 parser.add_option('--monolithic', dest='monolithic',
1015 action='store_true', default=False,
1016 help='Run in monolithic mode (without presenter)')
Jon Salz0697cbf2012-07-04 15:14:04 +08001017 (self.options, self.args) = parser.parse_args(args)
1018
Joel Kitching261e0422017-03-30 16:52:01 -07001019 signal.signal(signal.SIGINT, self.handle_signal)
1020 signal.signal(signal.SIGTERM, self.handle_signal)
Hung-Te Lina846f602014-07-04 20:32:22 +08001021 # TODO(hungte) SIGTERM does not work properly without Telemetry and should
1022 # be fixed.
Hung-Te Lina846f602014-07-04 20:32:22 +08001023
Jon Salz46b89562012-07-05 11:49:22 +08001024 # Make sure factory directories exist.
Peter Shihb4e49352017-05-25 17:35:11 +08001025 for path in [
1026 paths.DATA_LOG_DIR, paths.DATA_STATE_DIR, paths.DATA_TESTS_DIR]:
1027 file_utils.TryMakeDirs(path)
Jon Salz46b89562012-07-05 11:49:22 +08001028
Peter Shihfdf17682017-05-26 11:38:39 +08001029 global _inited_logging # pylint: disable=global-statement
Jon Salz0697cbf2012-07-04 15:14:04 +08001030 if not _inited_logging:
1031 factory.init_logging('goofy', verbose=self.options.verbose)
1032 _inited_logging = True
Jon Salz8fa8e832012-07-13 19:04:09 +08001033
Wei-Han Chen78f35f62017-03-06 20:11:20 +08001034 try:
1035 goofy_default_options = config_utils.LoadConfig(validate_schema=False)
1036 for key, value in goofy_default_options.iteritems():
1037 if getattr(self.options, key, None) is None:
1038 logging.info('self.options.%s = %r', key, value)
1039 setattr(self.options, key, value)
1040 except Exception:
1041 logging.exception('failed to load goofy overriding options')
1042
Jon Salz0f996602012-10-03 15:26:48 +08001043 if self.options.print_test_list:
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +08001044 all_test_lists, unused_errors = self.test_list_manager.BuildAllTestLists()
1045 test_list = (
1046 all_test_lists[self.options.print_test_list].ToFactoryTestList())
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001047 print(test_list.__repr__(recursive=True))
Jon Salz0f996602012-10-03 15:26:48 +08001048 sys.exit(0)
1049
Jon Salzee85d522012-07-17 14:34:46 +08001050 event_log.IncrementBootSequence()
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +08001051 testlog_goofy.IncrementInitCount()
1052
Jon Salzd15bbcf2013-05-21 17:33:57 +08001053 # Don't defer logging the initial event, so we can make sure
1054 # that device_id, reimage_id, etc. are all set up.
1055 self.event_log = EventLog('goofy', defer=False)
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +08001056 self.testlog = testlog.Testlog(
Peter Shihb4e49352017-05-25 17:35:11 +08001057 log_root=paths.DATA_LOG_DIR, uuid=self.uuid,
Joel Kitchingfa847512017-03-31 02:26:14 +08001058 stationDeviceId=testlog_goofy.GetDeviceID(),
1059 stationInstallationId=testlog_goofy.GetInstallationID())
Jon Salz0697cbf2012-07-04 15:14:04 +08001060
Jon Salz0697cbf2012-07-04 15:14:04 +08001061 if env:
1062 self.env = env
Hung-Te Linf5f2d7f2016-01-08 17:12:46 +08001063 elif sys_utils.InChroot():
Jon Salz0697cbf2012-07-04 15:14:04 +08001064 self.env = test_environment.FakeChrootEnvironment()
Hung-Te Lina846f602014-07-04 20:32:22 +08001065 elif self.options.ui == 'chrome':
Ricky Liang09d66d82014-09-25 11:20:54 +08001066 self.env = test_environment.DUTEnvironment()
Jon Salz0697cbf2012-07-04 15:14:04 +08001067 self.env.goofy = self
1068
1069 if self.options.restart:
1070 state.clear_state()
1071
Jon Salz0697cbf2012-07-04 15:14:04 +08001072 logging.info('Started')
1073
Hung-Te Lin8f6a3782015-01-06 22:58:32 +08001074 if not self.options.monolithic:
Hung-Te Lin7bd55312014-12-30 16:43:36 +08001075 self.link_manager = PresenterLinkManager(
1076 check_interval=1,
1077 handshake_timeout=self.options.handshake_timeout,
1078 standalone=self.options.standalone)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001079
Earl Ouacbe99c2017-02-21 16:04:19 +08001080 self.start_goofy_server()
1081 self.init_state_instance()
Peter Shih80e78b42017-03-10 17:00:56 +08001082 self.init_i18n()
Jon Salz0697cbf2012-07-04 15:14:04 +08001083 self.last_shutdown_time = (
Ricky Liang45c73e72015-01-15 15:00:30 +08001084 self.state_instance.get_shared_data('shutdown_time', optional=True))
Jon Salz0697cbf2012-07-04 15:14:04 +08001085 self.state_instance.del_shared_data('shutdown_time', optional=True)
Jon Salzb19ea072013-02-07 16:35:00 +08001086 self.state_instance.del_shared_data('startup_error', optional=True)
Jon Salz0697cbf2012-07-04 15:14:04 +08001087
Ricky Liang6fe218c2013-12-27 15:17:17 +08001088 self.options.automation_mode = ParseAutomationMode(
1089 self.options.automation_mode)
1090 self.state_instance.set_shared_data('automation_mode',
1091 self.options.automation_mode)
1092 self.state_instance.set_shared_data(
1093 'automation_mode_prompt',
1094 AutomationModePrompt[self.options.automation_mode])
1095
Joel Kitching50a63ea2016-02-22 13:15:09 +08001096 success = False
1097 exc_info = None
Jon Salz128b0932013-07-03 16:55:26 +08001098 try:
Joel Kitching50a63ea2016-02-22 13:15:09 +08001099 success = self.InitTestLists()
Hung-Te Linc8174b52017-06-02 11:11:45 +08001100 except Exception:
Joel Kitching50a63ea2016-02-22 13:15:09 +08001101 exc_info = sys.exc_info()
1102
1103 if not success:
1104 if exc_info:
1105 logging.exception('Unable to initialize test lists')
Chih-Yu Huang1725d622017-03-24 16:08:35 +08001106 self._RecordStartError(
1107 'Unable to initialize test lists\n%s' % traceback.format_exc())
Jon Salzb19ea072013-02-07 16:35:00 +08001108 if self.options.ui == 'chrome':
1109 # Create an empty test list with default options so that the rest of
1110 # startup can proceed.
Peter Shihd4ad0c92017-08-14 16:21:54 +08001111 self.test_list = manager.LegacyTestList(factory.FactoryTestList(
1112 [], self.state_instance, factory.Options()))
Jon Salzb19ea072013-02-07 16:35:00 +08001113 else:
1114 # Bail with an error; no point in starting up.
1115 sys.exit('No valid test list; exiting.')
1116
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001117 self.init_hooks()
1118
Jon Salz822838b2013-03-25 17:32:33 +08001119 if self.test_list.options.clear_state_on_start:
1120 self.state_instance.clear_test_state()
1121
Jon Salz670ce062014-05-16 15:53:50 +08001122 # If the phase is invalid, this will raise a ValueError.
1123 phase.SetPersistentPhase(self.test_list.options.phase)
1124
Peter Shih3b0bb9f2017-03-21 16:23:32 +08001125 if not self.state_instance.has_shared_data('ui_locale'):
1126 if self.test_list.options.ui_lang is not None:
1127 # For backward compatibility
1128 ui_locale = ('en-US'
1129 if self.test_list.options.ui_lang == 'en' else 'zh-CN')
1130 else:
1131 ui_locale = self.test_list.options.ui_locale
1132 self.state_instance.set_shared_data('ui_locale', ui_locale)
Jon Salz0697cbf2012-07-04 15:14:04 +08001133 self.state_instance.set_shared_data(
Ricky Liang45c73e72015-01-15 15:00:30 +08001134 'test_list_options',
Peter Shih90425db2017-08-02 15:53:48 +08001135 self.test_list.options.ToDict())
Jon Salz0697cbf2012-07-04 15:14:04 +08001136 self.state_instance.test_list = self.test_list
1137
Jon Salz23926422012-09-01 03:38:13 +08001138 if self.options.dummy_shopfloor:
Ricky Liang45c73e72015-01-15 15:00:30 +08001139 os.environ[shopfloor.SHOPFLOOR_SERVER_ENV_VAR_NAME] = (
1140 'http://%s:%d/' %
Joel Kitchingb85ed7f2014-10-08 18:24:39 +08001141 (net_utils.LOCALHOST, shopfloor.DEFAULT_SERVER_PORT))
Hung-Te Lin4e6357c2016-01-08 14:32:00 +08001142 self.dummy_shopfloor = process_utils.Spawn(
Peter Shihad166772017-05-31 11:36:17 +08001143 [os.path.join(paths.FACTORY_DIR, 'bin', 'shopfloor_server'),
Jon Salz23926422012-09-01 03:38:13 +08001144 '--dummy'])
1145 elif self.test_list.options.shopfloor_server_url:
1146 shopfloor.set_server_url(self.test_list.options.shopfloor_server_url)
Jon Salz2bf2f6b2013-03-28 18:49:26 +08001147 shopfloor.set_enabled(True)
Jon Salz23926422012-09-01 03:38:13 +08001148
Jon Salz0697cbf2012-07-04 15:14:04 +08001149 self.init_states()
1150 self.start_event_server()
Hung-Te Lincc41d2a2014-10-29 13:35:20 +08001151
Earl Oua3bca122016-10-21 16:00:30 +08001152 # Load and run Goofy plugins.
1153 self.plugin_controller = plugin_controller.PluginController(
1154 self.test_list.options.plugin_config_name, self)
1155 self.plugin_controller.StartAllPlugins()
1156
Chih-Yu Huang97103ae2017-03-20 18:22:54 +08001157 # TODO(akahuang): Move this part into a pytest.
1158 # Prepare DUT link after the plugins start running, because the link might
1159 # need the network connection.
1160 if success:
1161 try:
1162 if self.test_list.options.dut_options:
1163 logging.info('dut_options set by %s: %r', self.test_list.test_list_id,
1164 self.test_list.options.dut_options)
1165 device_utils.PrepareDUTLink(**self.test_list.options.dut_options)
1166 except Exception:
1167 logging.exception('Unable to prepare DUT link.')
Chih-Yu Huang1725d622017-03-24 16:08:35 +08001168 self._RecordStartError(
Chih-Yu Huang97103ae2017-03-20 18:22:54 +08001169 'Unable to prepare DUT link.\n%s' % traceback.format_exc())
1170
Jon Salz0697cbf2012-07-04 15:14:04 +08001171 # Note that we create a log watcher even if
1172 # sync_event_log_period_secs isn't set (no background
1173 # syncing), since we may use it to flush event logs as well.
1174 self.log_watcher = EventLogWatcher(
Ricky Liang45c73e72015-01-15 15:00:30 +08001175 self.test_list.options.sync_event_log_period_secs,
1176 event_log_db_file=None,
1177 handle_event_logs_callback=self.handle_event_logs)
Jon Salz0697cbf2012-07-04 15:14:04 +08001178 if self.test_list.options.sync_event_log_period_secs:
1179 self.log_watcher.StartWatchThread()
1180
Shen-En Shihf4ad32f2017-07-31 15:56:39 +08001181 self.event_client.post_event(
1182 Event(Event.Type.UPDATE_SYSTEM_INFO))
Jon Salz0697cbf2012-07-04 15:14:04 +08001183
1184 os.environ['CROS_FACTORY'] = '1'
1185 os.environ['CROS_DISABLE_SITE_SYSINFO'] = '1'
1186
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001187 # Should not move earlier.
1188 self.hooks.OnStartup()
1189
Ricky Liang36512a32014-07-25 11:47:04 +08001190 # Only after this point the Goofy backend is ready for UI connection.
1191 self.ready_for_ui_connection = True
1192
Jon Salz0697cbf2012-07-04 15:14:04 +08001193 def state_change_callback(test, test_state):
1194 self.event_client.post_event(
Ricky Liang4bff3e32014-02-20 18:46:11 +08001195 Event(Event.Type.STATE_CHANGE, path=test.path, state=test_state))
Jon Salz0697cbf2012-07-04 15:14:04 +08001196 self.test_list.state_change_callback = state_change_callback
Jon Salz73e0fd02012-04-04 11:46:38 +08001197
Vic Yange2c76a82014-10-30 12:48:19 -07001198 self.pytest_prespawner = prespawner.PytestPrespawner()
1199 self.pytest_prespawner.start()
Jon Salza6711d72012-07-18 14:33:03 +08001200
Ricky Liang48e47f92014-02-26 19:31:51 +08001201 tests_after_shutdown = self.state_instance.get_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001202 TESTS_AFTER_SHUTDOWN, optional=True)
Jon Salz5c344f62012-07-13 14:31:16 +08001203 force_auto_run = (tests_after_shutdown == FORCE_AUTO_RUN)
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001204
Jon Salz5c344f62012-07-13 14:31:16 +08001205 if not force_auto_run and tests_after_shutdown is not None:
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001206 logging.info('Resuming tests after shutdown: %r', tests_after_shutdown)
1207 self.test_list_iterator = tests_after_shutdown
Wei-Han Chenbcac7252017-04-21 19:46:51 +08001208 self.test_list_iterator.SetTestList(self.test_list)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001209 self.run_enqueue(self.run_next_test)
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001210 elif force_auto_run or self.test_list.options.auto_run_on_start:
1211 # If automation mode is enabled, allow suppress auto_run_on_start.
1212 if (self.options.automation_mode == 'NONE' or
1213 self.options.auto_run_on_start):
1214 status_filter = [TestState.UNTESTED]
1215 if self.test_list.options.retry_failed_on_start:
1216 status_filter.append(TestState.FAILED)
1217 self.run_enqueue(lambda: self.run_tests(self.test_list, status_filter))
1218 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, None)
Ricky Liang4bff3e32014-02-20 18:46:11 +08001219 self.restore_active_run_state()
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001220
Hung-Te Lin410f70a2015-12-15 14:53:42 +08001221 self.dut.hooks.OnTestStart()
Vic Yang08505c72015-01-06 17:01:53 -08001222
Dean Liao592e4d52013-01-10 20:06:39 +08001223 self.may_disable_cros_shortcut_keys()
1224
1225 def may_disable_cros_shortcut_keys(self):
1226 test_options = self.test_list.options
1227 if test_options.disable_cros_shortcut_keys:
1228 logging.info('Filter ChromeOS shortcut keys.')
1229 self.key_filter = KeyFilter(
1230 unmap_caps_lock=test_options.disable_caps_lock,
1231 caps_lock_keycode=test_options.caps_lock_keycode)
1232 self.key_filter.Start()
1233
Peter Ammon1e1ec572014-06-26 17:56:32 -07001234 def perform_periodic_tasks(self):
1235 """Override of base method to perform periodic work.
Vic Yang4953fc12012-07-26 16:19:53 +08001236
Peter Ammon1e1ec572014-06-26 17:56:32 -07001237 This method must not raise exceptions.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001238 """
Peter Ammon1e1ec572014-06-26 17:56:32 -07001239 super(Goofy, self).perform_periodic_tasks()
Jon Salzb22d1172012-08-06 10:38:57 +08001240
Earl Oua3bca122016-10-21 16:00:30 +08001241 self.check_plugins()
cychiang21886742012-07-05 15:16:32 +08001242 self.check_for_updates()
Jon Salz57717ca2012-04-04 16:47:25 +08001243
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001244 def handle_event_logs(self, chunks, periodic=False):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001245 """Callback for event watcher.
Jon Salz258a40c2012-04-19 12:34:01 +08001246
Jon Salz0697cbf2012-07-04 15:14:04 +08001247 Attempts to upload the event logs to the shopfloor server.
Vic Yang93027612013-05-06 02:42:49 +08001248
1249 Args:
Jon Salzd15bbcf2013-05-21 17:33:57 +08001250 chunks: A list of Chunk objects.
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001251 periodic: This event log handling is periodic. Error messages
1252 will only be shown for the first time.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001253 """
Vic Yang93027612013-05-06 02:42:49 +08001254 first_exception = None
1255 exception_count = 0
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001256 # Suppress error messages for periodic event syncing except for the
1257 # first time. If event syncing is not periodic, always show the error
1258 # messages.
1259 quiet = self._suppress_event_log_error_messages if periodic else False
Vic Yang93027612013-05-06 02:42:49 +08001260
Jon Salzd15bbcf2013-05-21 17:33:57 +08001261 for chunk in chunks:
Vic Yang93027612013-05-06 02:42:49 +08001262 try:
Jon Salzcddb6402013-05-23 12:56:42 +08001263 description = 'event logs (%s)' % str(chunk)
Vic Yang93027612013-05-06 02:42:49 +08001264 start_time = time.time()
1265 shopfloor_client = shopfloor.get_instance(
Ricky Liang45c73e72015-01-15 15:00:30 +08001266 detect=True,
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001267 timeout=self.test_list.options.shopfloor_timeout_secs,
1268 quiet=quiet)
Ricky Liang45c73e72015-01-15 15:00:30 +08001269 shopfloor_client.UploadEvent(chunk.log_name + '.' +
Jon Salzd15bbcf2013-05-21 17:33:57 +08001270 event_log.GetReimageId(),
1271 Binary(chunk.chunk))
Vic Yang93027612013-05-06 02:42:49 +08001272 logging.info(
Ricky Liang45c73e72015-01-15 15:00:30 +08001273 'Successfully synced %s in %.03f s',
1274 description, time.time() - start_time)
Hung-Te Linc8174b52017-06-02 11:11:45 +08001275 except Exception:
Hung-Te Linf707b242016-01-08 23:11:42 +08001276 first_exception = (first_exception or
1277 (chunk.log_name + ': ' +
1278 debug_utils.FormatExceptionOnly()))
Vic Yang93027612013-05-06 02:42:49 +08001279 exception_count += 1
1280
1281 if exception_count:
1282 if exception_count == 1:
1283 msg = 'Log upload failed: %s' % first_exception
1284 else:
1285 msg = '%d log upload failed; first is: %s' % (
1286 exception_count, first_exception)
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001287 # For periodic event log syncing, only show the first error messages.
1288 if periodic:
1289 if not self._suppress_event_log_error_messages:
1290 self._suppress_event_log_error_messages = True
1291 logging.warning('Suppress periodic shopfloor error messages for '
1292 'event log syncing after the first one.')
1293 raise Exception(msg)
1294 # For event log syncing by request, show the error messages.
1295 else:
1296 raise Exception(msg)
Vic Yang93027612013-05-06 02:42:49 +08001297
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001298 def run_tests_with_status(self, statuses_to_run, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001299 """Runs all top-level tests with a particular status.
Jon Salz0405ab52012-03-16 15:26:52 +08001300
Jon Salz0697cbf2012-07-04 15:14:04 +08001301 All active tests, plus any tests to re-run, are reset.
Jon Salz57717ca2012-04-04 16:47:25 +08001302
Jon Salz0697cbf2012-07-04 15:14:04 +08001303 Args:
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001304 statuses_to_run: The particular status that caller wants to run.
Jon Salz0697cbf2012-07-04 15:14:04 +08001305 starting_at: If provided, only auto-runs tests beginning with
1306 this test.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001307 root: The root of tests to run. If not provided, it will be
1308 the root of all tests.
1309 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001310 root = root or self.test_list
Jon Salz6dc031d2013-06-19 13:06:23 +08001311 self.abort_active_tests('Operator requested run/re-run of certain tests')
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001312 self.run_tests(root, status_filter=statuses_to_run)
Jon Salz0405ab52012-03-16 15:26:52 +08001313
Jon Salz0697cbf2012-07-04 15:14:04 +08001314 def restart_tests(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001315 """Restarts all tests."""
Jon Salz0697cbf2012-07-04 15:14:04 +08001316 root = root or self.test_list
Jon Salz0405ab52012-03-16 15:26:52 +08001317
Jon Salz6dc031d2013-06-19 13:06:23 +08001318 self.abort_active_tests('Operator requested restart of certain tests')
Wei-Han Chen3ae204c2017-04-28 19:36:55 +08001319 for test in root.Walk():
1320 test.UpdateState(status=TestState.UNTESTED)
Jon Salz0697cbf2012-07-04 15:14:04 +08001321 self.run_tests(root)
Hung-Te Lin96632362012-03-20 21:14:18 +08001322
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001323 def auto_run(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001324 """"Auto-runs" tests that have not been run yet.
Hung-Te Lin96632362012-03-20 21:14:18 +08001325
Jon Salz0697cbf2012-07-04 15:14:04 +08001326 Args:
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001327 root: If provided, the root of tests to run. If not provided, the root
1328 will be test_list (root of all tests).
1329 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001330 root = root or self.test_list
1331 self.run_tests_with_status([TestState.UNTESTED, TestState.ACTIVE],
Ricky Liang45c73e72015-01-15 15:00:30 +08001332 root=root)
Jon Salz968e90b2012-03-18 16:12:43 +08001333
Jon Salz0697cbf2012-07-04 15:14:04 +08001334 def handle_switch_test(self, event):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001335 """Switches to a particular test.
Jon Salz0405ab52012-03-16 15:26:52 +08001336
Ricky Liang6fe218c2013-12-27 15:17:17 +08001337 Args:
1338 event: The SWITCH_TEST event.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001339 """
Wei-Han Chen3ae204c2017-04-28 19:36:55 +08001340 test = self.test_list.LookupPath(event.path)
Jon Salz0697cbf2012-07-04 15:14:04 +08001341 if not test:
1342 logging.error('Unknown test %r', event.key)
1343 return
Jon Salz73e0fd02012-04-04 11:46:38 +08001344
Jon Salz0697cbf2012-07-04 15:14:04 +08001345 invoc = self.invocations.get(test)
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001346 if invoc:
Jon Salz0697cbf2012-07-04 15:14:04 +08001347 # Already running: just bring to the front if it
1348 # has a UI.
1349 logging.info('Setting visible test to %s', test.path)
Jon Salz36fbbb52012-07-05 13:45:06 +08001350 self.set_visible_test(test)
Jon Salz0697cbf2012-07-04 15:14:04 +08001351 return
Jon Salz73e0fd02012-04-04 11:46:38 +08001352
Jon Salz6dc031d2013-06-19 13:06:23 +08001353 self.abort_active_tests('Operator requested abort (switch_test)')
Wei-Han Chen3ae204c2017-04-28 19:36:55 +08001354 for t in test.Walk():
1355 t.UpdateState(status=TestState.UNTESTED)
Jon Salz73e0fd02012-04-04 11:46:38 +08001356
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001357 self.run_tests(test)
Jon Salz73e0fd02012-04-04 11:46:38 +08001358
Wei-Ning Huang38b75f02015-02-25 18:25:14 +08001359 def handle_key_filter_mode(self, event):
1360 if self.key_filter:
1361 if getattr(event, 'enabled'):
1362 self.key_filter.Start()
1363 else:
1364 self.key_filter.Stop()
1365
Jon Salz0697cbf2012-07-04 15:14:04 +08001366 def wait(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001367 """Waits for all pending invocations.
Jon Salz0697cbf2012-07-04 15:14:04 +08001368
1369 Useful for testing.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001370 """
Jon Salz1acc8742012-07-17 17:45:55 +08001371 while self.invocations:
1372 for k, v in self.invocations.iteritems():
1373 logging.info('Waiting for %s to complete...', k)
1374 v.thread.join()
1375 self.reap_completed_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +08001376
Claire Changd1961a22015-08-05 16:15:55 +08001377 def test_fail(self, test):
Hung-Te Lin410f70a2015-12-15 14:53:42 +08001378 self.dut.hooks.OnTestFailure(test)
Claire Changd1961a22015-08-05 16:15:55 +08001379 if self.link_manager:
1380 self.link_manager.UpdateStatus(False)
1381
Wei-Han Chenced08ef2016-11-08 09:40:02 +08001382
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001383if __name__ == '__main__':
Peter Ammona3d298c2014-09-23 10:11:02 -07001384 Goofy.run_main_and_exit()