blob: d3669ede2a15cc75c4131d7af35d4233f70e3eaf [file] [log] [blame]
You-Cheng Syud5692942018-01-04 14:40:59 +08001#!/usr/bin/env python
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
Earl Ouacbe99c2017-02-21 16:04:19 +080035from cros.factory.test.env import goofy_proxy
Hung-Te Linb6287242016-05-18 14:39:05 +080036from cros.factory.test.env import paths
Jon Salz83591782012-06-26 11:09:58 +080037from cros.factory.test.event import Event
Shen-En Shihd7359cc2017-10-03 16:01:47 +080038from cros.factory.test.event import ThreadingEventClient
Jon Salz83591782012-06-26 11:09:58 +080039from cros.factory.test.event import EventServer
Hung-Te Linb6287242016-05-18 14:39:05 +080040from cros.factory.test import event_log
41from cros.factory.test.event_log import EventLog
Hung-Te Linb6287242016-05-18 14:39:05 +080042from cros.factory.test.event_log import GetBootSequence
Hung-Te Lin91492a12014-11-25 18:56:30 +080043from cros.factory.test.event_log_watcher import EventLogWatcher
Peter Shihf65db932017-03-22 17:06:34 +080044from cros.factory.test.i18n import test_ui as i18n_test_ui
Peter Shih80e78b42017-03-10 17:00:56 +080045from cros.factory.test.i18n import translation
Hung-Te Lin3f096842016-01-13 17:37:06 +080046from cros.factory.test.rules import phase
Hung-Te Lind151bf32017-08-30 11:05:47 +080047from cros.factory.test import server_proxy
Hung-Te Linda8eb992017-09-28 03:27:12 +080048from cros.factory.test import session
Earl Oua3bca122016-10-21 16:00:30 +080049from cros.factory.test import state
Wei-Han Chen3b030492017-10-12 11:43:27 +080050from cros.factory.test.state import TestState
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +080051from cros.factory.test.test_lists import manager
Wei-Han Chen03113912017-09-29 15:58:25 +080052from cros.factory.test.test_lists import test_object
chuntseneb33f9d2017-05-12 13:38:17 +080053from cros.factory.testlog import testlog
Hung-Te Linb6287242016-05-18 14:39:05 +080054from cros.factory.tools.key_filter import KeyFilter
Wei-Han Chen78f35f62017-03-06 20:11:20 +080055from cros.factory.utils import config_utils
Hung-Te Linf707b242016-01-08 23:11:42 +080056from cros.factory.utils import debug_utils
Jon Salz2af235d2013-06-24 14:47:21 +080057from cros.factory.utils import file_utils
Hung-Te Lin8fc0d652017-09-21 13:05:44 +080058from cros.factory.utils import log_utils
Joel Kitchingb85ed7f2014-10-08 18:24:39 +080059from cros.factory.utils import net_utils
Hung-Te Lin4e6357c2016-01-08 14:32:00 +080060from cros.factory.utils import sys_utils
Hung-Te Linf707b242016-01-08 23:11:42 +080061from cros.factory.utils import type_utils
Hung-Te Linf2f78f72012-02-08 19:27:11 +080062
Earl Ou6de96c02017-05-19 18:51:28 +080063from cros.factory.external import syslog
64
Hung-Te Linf2f78f72012-02-08 19:27:11 +080065
Hung-Te Linf2f78f72012-02-08 19:27:11 +080066HWID_CFG_PATH = '/usr/local/share/chromeos-hwid/cfg'
Peter Shihb4e49352017-05-25 17:35:11 +080067CACHES_DIR = os.path.join(paths.DATA_STATE_DIR, 'caches')
Hung-Te Linf2f78f72012-02-08 19:27:11 +080068
Jon Salz5c344f62012-07-13 14:31:16 +080069# Value for tests_after_shutdown that forces auto-run (e.g., after
70# a factory update, when the available set of tests might change).
71FORCE_AUTO_RUN = 'force_auto_run'
72
Wei-Han Chenc17b4112016-11-22 14:56:51 +080073# Key to load the test list iterator after shutdown test
74TESTS_AFTER_SHUTDOWN = 'tests_after_shutdown'
75
Hung-Te Linf707b242016-01-08 23:11:42 +080076Status = type_utils.Enum(['UNINITIALIZED', 'INITIALIZING', 'RUNNING',
Wei-Han Chen2ebb92d2016-01-12 14:51:41 +080077 'TERMINATING', 'TERMINATED'])
Jon Salzd7550792013-07-12 05:49:27 +080078
Hung-Te Lina452d4d2017-10-25 17:46:14 +080079RUN_QUEUE_TIMEOUT_SECS = 10
80
81class Goofy(object):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +080082 """The main factory flow.
Jon Salz0697cbf2012-07-04 15:14:04 +080083
84 Note that all methods in this class must be invoked from the main
85 (event) thread. Other threads, such as callbacks and TestInvocation
86 methods, should instead post events on the run queue.
87
88 TODO: Unit tests. (chrome-os-partner:7409)
89
90 Properties:
Hung-Te Lina452d4d2017-10-25 17:46:14 +080091 run_queue: A queue of callbacks to invoke from the main thread.
92 exceptions: List of exceptions encountered in invocation threads.
93 last_idle: The most recent time of invoking the idle queue handler, or none.
Jon Salz0697cbf2012-07-04 15:14:04 +080094 uuid: A unique UUID for this invocation of Goofy.
95 state_instance: An instance of FactoryState.
96 state_server: The FactoryState XML/RPC server.
97 state_server_thread: A thread running state_server.
98 event_server: The EventServer socket server.
99 event_server_thread: A thread running event_server.
100 event_client: A client to the event server.
Earl Oua3bca122016-10-21 16:00:30 +0800101 plugin_controller: The PluginController object.
Peter Shih06d08212018-01-19 17:15:57 +0800102 invocations: A map from TestInvocation uuid to the corresponding
Jon Salz0697cbf2012-07-04 15:14:04 +0800103 TestInvocations objects representing active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +0800104 options: Command-line options.
105 args: Command-line args.
106 test_list: The test list.
Jon Salz128b0932013-07-03 16:55:26 +0800107 test_lists: All new-style test lists.
Ricky Liang4bff3e32014-02-20 18:46:11 +0800108 run_id: The identifier for latest test run.
109 scheduled_run_tests: The list of tests scheduled for latest test run.
Jon Salz0697cbf2012-07-04 15:14:04 +0800110 event_handlers: Map of Event.Type to the method used to handle that
111 event. If the method has an 'event' argument, the event is passed
112 to the handler.
Jon Salz416f9cc2013-05-10 18:32:50 +0800113 hooks: A Hooks object containing hooks for various Goofy actions.
Jon Salzd7550792013-07-12 05:49:27 +0800114 status: The current Goofy status (a member of the Status enum).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800115 """
Ricky Liang45c73e72015-01-15 15:00:30 +0800116
Jon Salz0697cbf2012-07-04 15:14:04 +0800117 def __init__(self):
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800118 self.run_queue = Queue.Queue()
119 self.exceptions = []
120 self.last_idle = None
121
Jon Salz0697cbf2012-07-04 15:14:04 +0800122 self.uuid = str(uuid.uuid4())
123 self.state_instance = None
Earl Ouacbe99c2017-02-21 16:04:19 +0800124 self.goofy_server = None
125 self.goofy_server_thread = None
Jon Salz16d10542012-07-23 12:18:45 +0800126 self.goofy_rpc = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800127 self.event_server = None
128 self.event_server_thread = None
129 self.event_client = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800130 self.log_watcher = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800131 self.event_log = None
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800132 self.testlog = None
Earl Oua3bca122016-10-21 16:00:30 +0800133 self.plugin_controller = None
Vic Yange2c76a82014-10-30 12:48:19 -0700134 self.pytest_prespawner = None
Vic Yanga3cecf82014-12-26 00:44:21 -0800135 self._ui_initialized = False
Jon Salz0697cbf2012-07-04 15:14:04 +0800136 self.invocations = {}
Jon Salz0697cbf2012-07-04 15:14:04 +0800137 self.chrome = None
Jon Salz416f9cc2013-05-10 18:32:50 +0800138 self.hooks = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800139
140 self.options = None
141 self.args = None
142 self.test_list = None
Jon Salz128b0932013-07-03 16:55:26 +0800143 self.test_lists = None
Ricky Liang4bff3e32014-02-20 18:46:11 +0800144 self.run_id = None
145 self.scheduled_run_tests = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800146 self.env = None
Jon Salzb22d1172012-08-06 10:38:57 +0800147 self.last_idle = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800148 self.last_shutdown_time = None
cychiang21886742012-07-05 15:16:32 +0800149 self.last_update_check = None
Cheng-Yi Chiang194d3c02015-03-16 14:37:15 +0800150 self._suppress_periodic_update_messages = False
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +0800151 self._suppress_event_log_error_messages = False
Earl Ouab979142016-10-25 16:48:06 +0800152 self.exclusive_resources = set()
Dean Liao592e4d52013-01-10 20:06:39 +0800153 self.key_filter = None
Jon Salzd7550792013-07-12 05:49:27 +0800154 self.status = Status.UNINITIALIZED
Ricky Liang36512a32014-07-25 11:47:04 +0800155 self.ready_for_ui_connection = False
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800156 self.is_restart_requested = False
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800157 self.test_list_iterator = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800158
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +0800159 self.test_list_manager = manager.Manager()
160
Hung-Te Lin6a72c642015-12-13 22:09:09 +0800161 # TODO(hungte) Support controlling remote DUT.
Hung-Te Linb6287242016-05-18 14:39:05 +0800162 self.dut = device_utils.CreateDUTInterface()
Hung-Te Lin6a72c642015-12-13 22:09:09 +0800163
Jon Salz85a39882012-07-05 16:45:04 +0800164 def test_or_root(event, parent_or_group=True):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800165 """Returns the test affected by a particular event.
Jon Salz85a39882012-07-05 16:45:04 +0800166
167 Args:
168 event: The event containing an optional 'path' attribute.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800169 parent_or_group: If True, returns the top-level parent for a test (the
Jon Salz85a39882012-07-05 16:45:04 +0800170 root node of the tests that need to be run together if the given test
171 path is to be run).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800172 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800173 try:
174 path = event.path
175 except AttributeError:
176 path = None
177
178 if path:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800179 test = self.test_list.LookupPath(path)
Jon Salz85a39882012-07-05 16:45:04 +0800180 if parent_or_group:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800181 test = test.GetTopLevelParentOrGroup()
Jon Salz85a39882012-07-05 16:45:04 +0800182 return test
Jon Salz0697cbf2012-07-04 15:14:04 +0800183 else:
Peter Shih999faf72017-07-07 11:32:42 +0800184 return self.test_list.ToFactoryTestList()
Jon Salz0697cbf2012-07-04 15:14:04 +0800185
186 self.event_handlers = {
Ricky Liang45c73e72015-01-15 15:00:30 +0800187 Event.Type.RESTART_TESTS:
188 lambda event: self.restart_tests(root=test_or_root(event)),
189 Event.Type.AUTO_RUN:
190 lambda event: self.auto_run(root=test_or_root(event)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800191 Event.Type.RUN_TESTS_WITH_STATUS:
192 lambda event: self.run_tests_with_status(
193 event.status,
194 root=test_or_root(event)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800195 Event.Type.UPDATE_SYSTEM_INFO:
196 lambda event: self.update_system_info(),
197 Event.Type.STOP:
198 lambda event: self.stop(root=test_or_root(event, False),
199 fail=getattr(event, 'fail', False),
200 reason=getattr(event, 'reason', None)),
Ricky Liang45c73e72015-01-15 15:00:30 +0800201 Event.Type.CLEAR_STATE:
202 lambda event: self.clear_state(
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800203 self.test_list.LookupPath(event.path)),
Wei-Ning Huang38b75f02015-02-25 18:25:14 +0800204 Event.Type.KEY_FILTER_MODE: self.handle_key_filter_mode,
Jon Salz0697cbf2012-07-04 15:14:04 +0800205 }
206
Jon Salz0697cbf2012-07-04 15:14:04 +0800207 self.web_socket_manager = None
208
209 def destroy(self):
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800210 """Performs any shutdown tasks."""
chuntsen9d675c62017-06-20 14:35:30 +0800211 # To avoid race condition when running shutdown test.
Peter Shih06d08212018-01-19 17:15:57 +0800212 for invoc in self.invocations.itervalues():
213 logging.info('Waiting for %s to complete...', invoc.test)
chuntsen9d675c62017-06-20 14:35:30 +0800214 invoc.thread.join(3) # Timeout in 3 seconds.
215
Jon Salzd7550792013-07-12 05:49:27 +0800216 self.status = Status.TERMINATING
Jon Salz0697cbf2012-07-04 15:14:04 +0800217 if self.chrome:
218 self.chrome.kill()
219 self.chrome = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800220 if self.web_socket_manager:
221 logging.info('Stopping web sockets')
222 self.web_socket_manager.close()
223 self.web_socket_manager = None
Earl Ouacbe99c2017-02-21 16:04:19 +0800224 if self.goofy_server_thread:
225 logging.info('Stopping goofy server')
Peter Shih0a6ae8d2017-10-23 17:59:42 +0800226 net_utils.ShutdownTCPServer(self.goofy_server)
Earl Ouacbe99c2017-02-21 16:04:19 +0800227 self.goofy_server_thread.join()
228 self.goofy_server.server_close()
229 self.goofy_server_thread = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800230 if self.state_instance:
231 self.state_instance.close()
232 if self.event_server_thread:
233 logging.info('Stopping event server')
Peter Shihce9490e2017-05-11 14:32:12 +0800234 net_utils.ShutdownTCPServer(self.event_server)
Jon Salz0697cbf2012-07-04 15:14:04 +0800235 self.event_server_thread.join()
236 self.event_server.server_close()
237 self.event_server_thread = None
238 if self.log_watcher:
239 if self.log_watcher.IsThreadStarted():
240 self.log_watcher.StopWatchThread()
241 self.log_watcher = None
Vic Yange2c76a82014-10-30 12:48:19 -0700242 if self.pytest_prespawner:
243 logging.info('Stopping pytest prespawner')
244 self.pytest_prespawner.stop()
245 self.pytest_prespawner = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800246 if self.event_client:
247 logging.info('Closing event client')
248 self.event_client.close()
249 self.event_client = None
250 if self.event_log:
251 self.event_log.Close()
252 self.event_log = None
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800253 if self.testlog:
254 self.testlog.Close()
255 self.testlog = None
Dean Liao592e4d52013-01-10 20:06:39 +0800256 if self.key_filter:
257 self.key_filter.Stop()
Earl Oua3bca122016-10-21 16:00:30 +0800258 if self.plugin_controller:
259 self.plugin_controller.StopAndDestroyAllPlugins()
260 self.plugin_controller = None
Dean Liao592e4d52013-01-10 20:06:39 +0800261
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800262 self.check_exceptions()
Jon Salz0697cbf2012-07-04 15:14:04 +0800263 logging.info('Done destroying Goofy')
Jon Salzd7550792013-07-12 05:49:27 +0800264 self.status = Status.TERMINATED
Jon Salz0697cbf2012-07-04 15:14:04 +0800265
Earl Ouacbe99c2017-02-21 16:04:19 +0800266 def start_goofy_server(self):
Hung-Te Lin6bfd1de2017-11-10 16:21:33 +0800267 logging.info('Starting goofy server')
Earl Ouacbe99c2017-02-21 16:04:19 +0800268 self.goofy_server = goofy_server.GoofyServer(
Shen-En Shihd5b96bf2017-08-09 17:47:21 +0800269 (goofy_proxy.DEFAULT_GOOFY_BIND, goofy_proxy.DEFAULT_GOOFY_PORT))
Earl Ouacbe99c2017-02-21 16:04:19 +0800270 self.goofy_server_thread = threading.Thread(
271 target=self.goofy_server.serve_forever,
272 name='GoofyServer')
273 self.goofy_server_thread.start()
274
Peter Shihbb771342017-10-19 16:42:28 +0800275 def init_static_files(self):
Peter Shih7cc81b12017-08-24 13:04:46 +0800276 static_path = os.path.join(paths.FACTORY_PYTHON_PACKAGE_DIR, 'goofy/static')
Earl Ouacbe99c2017-02-21 16:04:19 +0800277 # Setup static file path
Peter Shih7cc81b12017-08-24 13:04:46 +0800278 self.goofy_server.RegisterPath('/', static_path)
Earl Ouacbe99c2017-02-21 16:04:19 +0800279
280 def init_state_instance(self):
Jon Salz2af235d2013-06-24 14:47:21 +0800281 # Before starting state server, remount stateful partitions with
282 # no commit flag. The default commit time (commit=600) makes corruption
283 # too likely.
Hung-Te Lin1968d9c2016-01-08 22:55:46 +0800284 sys_utils.ResetCommitTime()
Earl Ouacbe99c2017-02-21 16:04:19 +0800285 self.state_instance = state.FactoryState()
286 self.goofy_server.AddRPCInstance(goofy_proxy.STATE_URL, self.state_instance)
Jon Salz2af235d2013-06-24 14:47:21 +0800287
Earl Ouacbe99c2017-02-21 16:04:19 +0800288 # Setup Goofy RPC.
289 # TODO(shunhsingou): separate goofy_rpc and state server instead of
290 # injecting goofy_rpc functions into state.
Jon Salz16d10542012-07-23 12:18:45 +0800291 self.goofy_rpc = GoofyRPC(self)
292 self.goofy_rpc.RegisterMethods(self.state_instance)
Jon Salz0697cbf2012-07-04 15:14:04 +0800293
Peter Shih80e78b42017-03-10 17:00:56 +0800294 def init_i18n(self):
295 js_data = 'var goofy_i18n_data = %s;' % translation.GetAllI18nDataJS()
Peter Shihce03c2e2017-03-21 17:36:10 +0800296 self.goofy_server.RegisterData('/js/goofy-translations.js',
297 'application/javascript', js_data)
Peter Shihf65db932017-03-22 17:06:34 +0800298 self.goofy_server.RegisterData('/css/i18n.css',
299 'text/css', i18n_test_ui.GetStyleSheet())
Peter Shih80e78b42017-03-10 17:00:56 +0800300
Jon Salz0697cbf2012-07-04 15:14:04 +0800301 def start_event_server(self):
302 self.event_server = EventServer()
303 logging.info('Starting factory event server')
304 self.event_server_thread = threading.Thread(
Ricky Liang45c73e72015-01-15 15:00:30 +0800305 target=self.event_server.serve_forever,
Peter Shihfdf17682017-05-26 11:38:39 +0800306 name='EventServer')
Jon Salz0697cbf2012-07-04 15:14:04 +0800307 self.event_server_thread.start()
308
Shen-En Shihd7359cc2017-10-03 16:01:47 +0800309 self.event_client = ThreadingEventClient(
Shen-En Shihba564cb2017-10-05 11:54:16 +0800310 callback=lambda event: self.run_queue.put(
311 lambda: self.handle_event(event)))
Jon Salz0697cbf2012-07-04 15:14:04 +0800312
313 self.web_socket_manager = WebSocketManager(self.uuid)
Earl Ouacbe99c2017-02-21 16:04:19 +0800314 self.goofy_server.AddHTTPGetHandler(
315 '/event', self.web_socket_manager.handle_web_socket)
Jon Salz0697cbf2012-07-04 15:14:04 +0800316
Ricky Liang48e47f92014-02-26 19:31:51 +0800317 def shutdown(self, operation):
318 """Starts shutdown procedure.
319
320 Args:
Vic (Chun-Ju) Yang05b0d952014-04-28 17:39:09 +0800321 operation: The shutdown operation (reboot, full_reboot, or halt).
Ricky Liang48e47f92014-02-26 19:31:51 +0800322 """
323 active_tests = []
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800324 for test in self.test_list.Walk():
325 if not test.IsLeaf():
Ricky Liang48e47f92014-02-26 19:31:51 +0800326 continue
327
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800328 test_state = test.GetState()
Ricky Liang48e47f92014-02-26 19:31:51 +0800329 if test_state.status == TestState.ACTIVE:
330 active_tests.append(test)
331
Ricky Liang48e47f92014-02-26 19:31:51 +0800332 if not (len(active_tests) == 1 and
Wei-Han Chen03113912017-09-29 15:58:25 +0800333 isinstance(active_tests[0], test_object.ShutdownStep)):
Ricky Liang48e47f92014-02-26 19:31:51 +0800334 logging.error(
335 'Calling Goofy shutdown outside of the shutdown factory test')
336 return
337
338 logging.info('Start Goofy shutdown (%s)', operation)
339 # Save pending test list in the state server
340 self.state_instance.set_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800341 TESTS_AFTER_SHUTDOWN, self.test_list_iterator)
Ricky Liang48e47f92014-02-26 19:31:51 +0800342 # Save shutdown time
343 self.state_instance.set_shared_data('shutdown_time', time.time())
344
345 with self.env.lock:
346 self.event_log.Log('shutdown', operation=operation)
347 shutdown_result = self.env.shutdown(operation)
348 if shutdown_result:
349 # That's all, folks!
Peter Ammon1e1ec572014-06-26 17:56:32 -0700350 self.run_enqueue(None)
Ricky Liang48e47f92014-02-26 19:31:51 +0800351 else:
352 # Just pass (e.g., in the chroot).
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800353 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, None)
Ricky Liang48e47f92014-02-26 19:31:51 +0800354 # Send event with no fields to indicate that there is no
355 # longer a pending shutdown.
356 self.event_client.post_event(Event(Event.Type.PENDING_SHUTDOWN))
357
358 def handle_shutdown_complete(self, test):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800359 """Handles the case where a shutdown was detected during a shutdown step.
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800360
Ricky Liang6fe218c2013-12-27 15:17:17 +0800361 Args:
362 test: The ShutdownStep.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800363 """
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800364 test_state = test.UpdateState(increment_shutdown_count=1)
Jon Salz0697cbf2012-07-04 15:14:04 +0800365 logging.info('Detected shutdown (%d of %d)',
Ricky Liang48e47f92014-02-26 19:31:51 +0800366 test_state.shutdown_count, test.iterations)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800367
Ricky Liang48e47f92014-02-26 19:31:51 +0800368 tests_after_shutdown = self.state_instance.get_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800369 TESTS_AFTER_SHUTDOWN, optional=True)
370
371 # Make this shutdown test the next test to run. This is to continue on
372 # post-shutdown verification in the shutdown step.
Ricky Liang48e47f92014-02-26 19:31:51 +0800373 if not tests_after_shutdown:
Wei-Han Chen29663c12017-06-27 10:28:54 +0800374 goofy_error = 'TESTS_AFTER_SHTUDOWN is not set'
Ricky Liang48e47f92014-02-26 19:31:51 +0800375 self.state_instance.set_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800376 TESTS_AFTER_SHUTDOWN, TestListIterator(test))
377 else:
Wei-Han Chen29663c12017-06-27 10:28:54 +0800378 goofy_error = tests_after_shutdown.RestartLastTest()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800379 self.state_instance.set_shared_data(
380 TESTS_AFTER_SHUTDOWN, tests_after_shutdown)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800381
Ricky Liang48e47f92014-02-26 19:31:51 +0800382 # Set 'post_shutdown' to inform shutdown test that a shutdown just occurred.
Ricky Liangb7eb8772014-09-15 18:05:22 +0800383 self.state_instance.set_shared_data(
Wei-Han Chen29663c12017-06-27 10:28:54 +0800384 state.KEY_POST_SHUTDOWN % test.path,
385 {'invocation': self.state_instance.get_test_state(test.path).invocation,
386 'goofy_error': goofy_error})
Jon Salz258a40c2012-04-19 12:34:01 +0800387
Jon Salz0697cbf2012-07-04 15:14:04 +0800388 def init_states(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800389 """Initializes all states on startup."""
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800390 for test in self.test_list.GetAllTests():
Jon Salz0697cbf2012-07-04 15:14:04 +0800391 # Make sure the state server knows about all the tests,
392 # defaulting to an untested state.
Peter Shih6e578272017-09-12 17:41:43 +0800393 test.UpdateState(update_parent=False)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800394
Earl Ouf76e55c2017-03-07 11:48:34 +0800395 is_unexpected_shutdown = False
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800396
Jon Salz0697cbf2012-07-04 15:14:04 +0800397 # Any 'active' tests should be marked as failed now.
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800398 for test in self.test_list.Walk():
399 if not test.IsLeaf():
Jon Salza6711d72012-07-18 14:33:03 +0800400 # Don't bother with parents; they will be updated when their
401 # children are updated.
402 continue
403
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800404 test_state = test.GetState()
Jon Salz0697cbf2012-07-04 15:14:04 +0800405 if test_state.status != TestState.ACTIVE:
406 continue
Wei-Han Chen03113912017-09-29 15:58:25 +0800407 if isinstance(test, test_object.ShutdownStep):
Jon Salz0697cbf2012-07-04 15:14:04 +0800408 # Shutdown while the test was active - that's good.
Ricky Liang48e47f92014-02-26 19:31:51 +0800409 self.handle_shutdown_complete(test)
Shen-En Shihef6c5ae2017-12-21 14:26:47 +0800410 elif test.allow_reboot:
411 is_unexpected_shutdown = True
412 test.UpdateState(status=TestState.UNTESTED)
413 # For "allow_reboot" tests (such as "Start"), don't cancel
414 # pending tests, since reboot is expected.
415 session.console.info('Unexpected shutdown while test %s was running. '
416 'The test is marked as allow_reboot, continuing '
417 'on pending tests.',
418 test.path)
Jon Salz0697cbf2012-07-04 15:14:04 +0800419 else:
Earl Ouf76e55c2017-03-07 11:48:34 +0800420 is_unexpected_shutdown = True
Jon Salz0697cbf2012-07-04 15:14:04 +0800421 error_msg = 'Unexpected shutdown while test was running'
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800422 # TODO(itspeter): Add testlog to collect expired session infos.
Jon Salz0697cbf2012-07-04 15:14:04 +0800423 self.event_log.Log('end_test',
Ricky Liang45c73e72015-01-15 15:00:30 +0800424 path=test.path,
425 status=TestState.FAILED,
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800426 invocation=test.GetState().invocation,
Earl Ouf76e55c2017-03-07 11:48:34 +0800427 error_msg=error_msg)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800428 test.UpdateState(
Ricky Liang45c73e72015-01-15 15:00:30 +0800429 status=TestState.FAILED,
430 error_msg=error_msg)
Chun-Ta Lin87c2dac2015-05-02 01:35:01 -0700431 # Trigger the OnTestFailure callback.
Claire Changd1961a22015-08-05 16:15:55 +0800432 self.run_queue.put(lambda: self.test_fail(test))
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800433
Shen-En Shihef6c5ae2017-12-21 14:26:47 +0800434 session.console.info('Unexpected shutdown while test %s '
435 'running; cancelling any pending tests',
436 test.path)
437 # cancel pending tests by replace the iterator with an empty one
438 self.state_instance.set_shared_data(
439 TESTS_AFTER_SHUTDOWN,
440 TestListIterator(None))
Jon Salz008f4ea2012-08-28 05:39:45 +0800441
Earl Ouf76e55c2017-03-07 11:48:34 +0800442 if is_unexpected_shutdown:
443 logging.warning("Unexpected shutdown.")
Wei-Han Chen8d7fbc42017-10-18 19:20:47 +0800444 self.hooks.OnUnexpectedReboot(self)
Earl Ouf76e55c2017-03-07 11:48:34 +0800445
Wei-Han Chen109d76f2017-08-08 18:50:35 +0800446 if self.test_list.options.read_device_data_from_vpd_on_init:
447 vpd_data = {}
448 for section in [device_data.NAME_RO, device_data.NAME_RW]:
449 try:
450 vpd_data[section] = self.dut.vpd.boot.GetPartition(section).GetAll()
451 except Exception:
452 logging.exception('Failed to read %s_VPD, ignored...',
453 section.upper())
454 # using None for key_map will use default key_map
455 device_data.UpdateDeviceDataFromVPD(None, vpd_data)
456
Wei-Han Chen212d2af2017-08-03 18:12:23 +0800457 # state_instance is initialized, we can mark skipped and waived tests now.
458 self.test_list.SetSkippedAndWaivedTests()
459
Jon Salz0697cbf2012-07-04 15:14:04 +0800460 def handle_event(self, event):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800461 """Handles an event from the event server."""
Jon Salz0697cbf2012-07-04 15:14:04 +0800462 handler = self.event_handlers.get(event.type)
463 if handler:
464 handler(event)
465 else:
466 # We don't register handlers for all event types - just ignore
467 # this event.
468 logging.debug('Unbound event type %s', event.type)
Jon Salz4f6c7172012-06-11 20:45:36 +0800469
Vic Yangaabf9fd2013-04-09 18:56:13 +0800470 def check_critical_factory_note(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800471 """Returns True if the last factory note is critical."""
Vic Yangaabf9fd2013-04-09 18:56:13 +0800472 notes = self.state_instance.get_shared_data('factory_note', True)
473 return notes and notes[-1]['level'] == 'CRITICAL'
474
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800475 def schedule_restart(self):
476 """Schedules a restart event when any invocation is completed."""
477 self.is_restart_requested = True
478
479 def invocation_completion(self):
480 """Callback when an invocation is completed."""
481 if self.is_restart_requested:
482 logging.info('Restart by scheduled event.')
483 self.is_restart_requested = False
484 self.restart_tests()
485 else:
486 self.run_next_test()
487
Jon Salz0697cbf2012-07-04 15:14:04 +0800488 def run_next_test(self):
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800489 """Runs the next eligible test.
henryhsu4cc6b022014-04-22 17:12:42 +0800490
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800491 self.test_list_iterator (a TestListIterator object) will determine which
492 test should be run.
henryhsu4cc6b022014-04-22 17:12:42 +0800493 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800494 self.reap_completed_tests()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800495
496 if self.invocations:
497 # there are tests still running, we cannot start new tests
Vic Yangaabf9fd2013-04-09 18:56:13 +0800498 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800499
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800500 if self.check_critical_factory_note():
501 logging.info('has critical factory note, stop running')
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800502 self.test_list_iterator.Stop()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800503 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800504
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800505 while True:
506 try:
507 path = self.test_list_iterator.next()
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800508 test = self.test_list.LookupPath(path)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800509 except StopIteration:
510 logging.info('no next test, stop running')
Jon Salz0697cbf2012-07-04 15:14:04 +0800511 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800512
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800513 # check if we have run all required tests
Jon Salz304a75d2012-07-06 11:14:15 +0800514 untested = set()
Jon Salza1412922012-07-23 16:04:17 +0800515 for requirement in test.require_run:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800516 for i in requirement.test.Walk():
Jon Salza1412922012-07-23 16:04:17 +0800517 if i == test:
Jon Salz304a75d2012-07-06 11:14:15 +0800518 # We've hit this test itself; stop checking
519 break
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800520 if ((i.GetState().status == TestState.UNTESTED) or
Wei-Han Chen3a160172017-07-11 17:31:28 +0800521 (requirement.passed and
522 i.GetState().status not in [TestState.SKIPPED,
523 TestState.PASSED])):
Jon Salz304a75d2012-07-06 11:14:15 +0800524 # Found an untested test; move on to the next
525 # element in require_run.
Jon Salza1412922012-07-23 16:04:17 +0800526 untested.add(i)
Jon Salz304a75d2012-07-06 11:14:15 +0800527 break
528
529 if untested:
530 untested_paths = ', '.join(sorted([x.path for x in untested]))
531 if self.state_instance.get_shared_data('engineering_mode',
532 optional=True):
533 # In engineering mode, we'll let it go.
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800534 session.console.warn('In engineering mode; running '
Jon Salz304a75d2012-07-06 11:14:15 +0800535 '%s even though required tests '
536 '[%s] have not completed',
537 test.path, untested_paths)
538 else:
539 # Not in engineering mode; mark it failed.
540 error_msg = ('Required tests [%s] have not been run yet'
541 % untested_paths)
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800542 session.console.error('Not running %s: %s',
Jon Salz304a75d2012-07-06 11:14:15 +0800543 test.path, error_msg)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800544 test.UpdateState(status=TestState.FAILED,
545 error_msg=error_msg)
Jon Salz304a75d2012-07-06 11:14:15 +0800546 continue
547
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800548 # okay, let's run the test
Wei-Han Chen03113912017-09-29 15:58:25 +0800549 if (isinstance(test, test_object.ShutdownStep) and
Ricky Liangb7eb8772014-09-15 18:05:22 +0800550 self.state_instance.get_shared_data(
Wei-Han Chen29663c12017-06-27 10:28:54 +0800551 state.KEY_POST_SHUTDOWN % test.path, optional=True)):
Ricky Liang48e47f92014-02-26 19:31:51 +0800552 # Invoking post shutdown method of shutdown test. We should retain the
553 # iterations_left and retries_left of the original test state.
554 test_state = self.state_instance.get_test_state(test.path)
555 self._run_test(test, test_state.iterations_left,
556 test_state.retries_left)
557 else:
558 # Starts a new test run; reset iterations and retries.
559 self._run_test(test, test.iterations, test.retries)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800560 return # to leave while
Jon Salz1acc8742012-07-17 17:45:55 +0800561
Peter Shih13d2ced2017-09-25 16:25:09 +0800562 def _run_test(self, test, iterations_left=None, retries_left=None,
563 set_layout=True):
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800564 """Invokes the test.
565
566 The argument `test` should be either a leaf test (no subtests) or a parallel
567 test (all subtests should be run in parallel).
568 """
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800569 if not self._ui_initialized and not test.IsNoHost():
Vic Yanga3cecf82014-12-26 00:44:21 -0800570 self.init_ui()
Jon Salz1acc8742012-07-17 17:45:55 +0800571
Peter Shih13d2ced2017-09-25 16:25:09 +0800572 if set_layout:
573 self.event_client.post_event(
574 Event(
575 Event.Type.SET_TEST_UI_LAYOUT,
576 layout_type=test.layout_type,
577 layout_options=test.layout_options))
578
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800579 if test.IsLeaf():
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800580 invoc = TestInvocation(
581 self, test, on_completion=self.invocation_completion,
582 on_test_failure=lambda: self.test_fail(test))
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800583 new_state = test.UpdateState(
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800584 status=TestState.ACTIVE, increment_count=1, error_msg='',
585 invocation=invoc.uuid, iterations_left=iterations_left,
Peter Shihf5c048d2017-09-01 17:57:51 +0800586 retries_left=retries_left)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800587 invoc.count = new_state.count
Peter Shih06d08212018-01-19 17:15:57 +0800588 self.invocations[invoc.uuid] = invoc
Peter Shihb2ecd552017-08-24 17:48:58 +0800589 # Send a INIT_TEST_UI event here, so the test UI are initialized in
590 # order, and the tab order would be same as test list order when there
591 # are parallel tests with UI.
592 self.event_client.post_event(
593 Event(
594 Event.Type.INIT_TEST_UI,
Peter Shihb2ecd552017-08-24 17:48:58 +0800595 test=test.path,
596 invocation=invoc.uuid))
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800597 self.check_plugins()
Peter Shih0d4f77a2018-01-19 16:15:49 +0800598 invoc.Start()
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800599 elif test.parallel:
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800600 for subtest in test.subtests:
601 # TODO(stimim): what if the subtests *must* be run in parallel?
602 # for example, stressapptest and countdown test.
603
604 # Make sure we don't need to skip it:
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800605 if not self.test_list_iterator.CheckSkip(subtest):
Peter Shih13d2ced2017-09-25 16:25:09 +0800606 self._run_test(subtest, subtest.iterations, subtest.retries,
607 set_layout=False)
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800608 else:
609 # This should never happen, there must be something wrong.
610 # However, we can't raise an exception, otherwise goofy will be closed
611 logging.critical(
612 'Goofy should not get a non-leaf test that is not parallel: %r',
613 test)
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800614 session.console.critical(
Wei-Han Chendc3e3ba2017-07-05 16:49:09 +0800615 'Goofy should not get a non-leaf test that is not parallel: %r',
616 test)
Jon Salz5f2a0672012-05-22 17:14:06 +0800617
Hung-Te Lina452d4d2017-10-25 17:46:14 +0800618 def run(self):
619 """Runs Goofy."""
620 # Process events forever.
621 while self.run_once(True):
622 pass
623
624 def run_enqueue(self, val):
625 """Enqueues an object on the event loop.
626
627 Generally this is a function. It may also be None to indicate that the
628 run queue should shut down.
629 """
630 self.run_queue.put(val)
631
632 def run_once(self, block=False):
633 """Runs all items pending in the event loop.
634
635 Args:
636 block: If true, block until at least one event is processed.
637
638 Returns:
639 True to keep going or False to shut down.
640 """
641 events = type_utils.DrainQueue(self.run_queue)
642 while not events:
643 # Nothing on the run queue.
644 self._run_queue_idle()
645 if block:
646 # Block for at least one event...
647 try:
648 events.append(self.run_queue.get(timeout=RUN_QUEUE_TIMEOUT_SECS))
649 except Queue.Empty:
650 # Keep going (calling _run_queue_idle() again at the top of
651 # the loop)
652 continue
653 # ...and grab anything else that showed up at the same
654 # time.
655 events.extend(type_utils.DrainQueue(self.run_queue))
656 else:
657 break
658
659 for event in events:
660 if not event:
661 # Shutdown request.
662 self.run_queue.task_done()
663 return False
664
665 try:
666 event()
667 except Exception:
668 logging.exception('Error in event loop')
669 self.record_exception(traceback.format_exception_only(
670 *sys.exc_info()[:2]))
671 # But keep going
672 finally:
673 self.run_queue.task_done()
674 return True
675
676 def _run_queue_idle(self):
677 """Invoked when the run queue has no events.
678
679 This method must not raise exception.
680 """
681 now = time.time()
682 if (self.last_idle and
683 now < (self.last_idle + RUN_QUEUE_TIMEOUT_SECS - 1)):
684 # Don't run more often than once every (RUN_QUEUE_TIMEOUT_SECS -
685 # 1) seconds.
686 return
687
688 self.last_idle = now
689 self.perform_periodic_tasks()
690
691 def check_exceptions(self):
692 """Raises an error if any exceptions have occurred in
693 invocation threads.
694 """
695 if self.exceptions:
696 raise RuntimeError('Exception in invocation thread: %r' %
697 self.exceptions)
698
699 def record_exception(self, msg):
700 """Records an exception in an invocation thread.
701
702 An exception with the given message will be rethrown when
703 Goofy is destroyed.
704 """
705 self.exceptions.append(msg)
706
707 @staticmethod
708 def drain_nondaemon_threads():
709 """Wait for all non-current non-daemon threads to exit.
710
711 This is performed by the Python runtime in an atexit handler,
712 but this implementation allows us to do more detailed logging, and
713 to support control-C for abrupt shutdown.
714 """
715 cur_thread = threading.current_thread()
716 all_threads_joined = False
717 while not all_threads_joined:
718 for thread in threading.enumerate():
719 if not thread.daemon and thread.is_alive() and thread is not cur_thread:
720 logging.info("Waiting for thread '%s'...", thread.name)
721 thread.join()
722 # We break rather than continue on because the thread list
723 # may have changed while we waited
724 break
725 else:
726 # No threads remain
727 all_threads_joined = True
728 return all_threads_joined
729
730 @staticmethod
731 def run_main_and_exit():
732 """Instantiate the receiver, run its main function, and exit when done.
733
734 This static method is the "entry point" for Goofy.
735 It instantiates the receiver and invokes its main function, while
736 handling exceptions. When main() finishes (normally or via an exception),
737 it exits the process.
738 """
739 try:
740 cls = Goofy
741 goofy = cls()
742 except Exception:
743 logging.info('Failed to instantiate %s, shutting down.', cls.__name__)
744 traceback.print_exc()
745 os._exit(1) # pylint: disable=protected-access
746 sys.exit(1)
747
748 try:
749 goofy.main()
750 except SystemExit:
751 # Propagate SystemExit without logging.
752 raise
753 except KeyboardInterrupt:
754 logging.info('Interrupted, shutting down...')
755 except Exception:
756 # Log the error before trying to shut down
757 logging.exception('Error in main loop')
758 raise
759 finally:
760 try:
761 # We drain threads manually, rather than letting Python do it,
762 # so that we can report to the user which threads are stuck
763 goofy.destroy()
764 cls.drain_nondaemon_threads()
765 except (KeyboardInterrupt, Exception):
766 # We got a keyboard interrupt while attempting to shut down.
767 # The user is waiting impatiently! This can happen if threads get stuck.
768 # We need to exit via os._exit, not sys.exit, because sys.exit() will
769 # run the main thread's atexit handler, which waits for all threads to
770 # exit, which is likely how we got stuck in the first place. However, we
771 # do want to capture all logs, so we shut down logging gracefully.
772 logging.info('Graceful shutdown interrupted, shutting down abruptly')
773 logging.shutdown()
774 os._exit(1) # pylint: disable=protected-access
775 # Normal exit path
776 sys.exit(0)
777
Earl Oua3bca122016-10-21 16:00:30 +0800778 def check_plugins(self):
779 """Check plugins to be paused or resumed."""
780 exclusive_resources = set()
Peter Shih06d08212018-01-19 17:15:57 +0800781 for invoc in self.invocations.itervalues():
Earl Oua3bca122016-10-21 16:00:30 +0800782 exclusive_resources = exclusive_resources.union(
Peter Shih06d08212018-01-19 17:15:57 +0800783 invoc.test.GetExclusiveResources())
Earl Oua3bca122016-10-21 16:00:30 +0800784 self.plugin_controller.PauseAndResumePluginByResource(exclusive_resources)
785
cychiang21886742012-07-05 15:16:32 +0800786 def check_for_updates(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800787 """Schedules an asynchronous check for updates if necessary."""
cychiang21886742012-07-05 15:16:32 +0800788 if not self.test_list.options.update_period_secs:
789 # Not enabled.
790 return
791
792 now = time.time()
793 if self.last_update_check and (
794 now - self.last_update_check <
795 self.test_list.options.update_period_secs):
796 # Not yet time for another check.
797 return
798
799 self.last_update_check = now
800
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800801 def handle_check_for_update(
Hung-Te Lind151bf32017-08-30 11:05:47 +0800802 reached_server, toolkit_version, needs_update):
803 if reached_server:
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800804 new_update_toolkit_version = toolkit_version if needs_update else None
805 if self.dut.info.update_toolkit_version != new_update_toolkit_version:
806 logging.info('Received new update TOOLKIT_VERSION: %s',
807 new_update_toolkit_version)
808 self.dut.info.Overrides('update_toolkit_version',
809 new_update_toolkit_version)
Peter Ammon1e1ec572014-06-26 17:56:32 -0700810 self.run_enqueue(self.update_system_info)
You-Cheng Syud4a24bf2017-08-21 17:56:48 +0800811 elif not self._suppress_periodic_update_messages:
812 logging.warning('Suppress error messages for periodic update checking '
813 'after the first one.')
814 self._suppress_periodic_update_messages = True
cychiang21886742012-07-05 15:16:32 +0800815
816 updater.CheckForUpdateAsync(
Hung-Te Lind151bf32017-08-30 11:05:47 +0800817 handle_check_for_update, None, self._suppress_periodic_update_messages)
cychiang21886742012-07-05 15:16:32 +0800818
Jon Salza6711d72012-07-18 14:33:03 +0800819 def cancel_pending_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800820 """Cancels any tests in the run queue."""
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800821 self.run_tests(None)
Jon Salza6711d72012-07-18 14:33:03 +0800822
Ricky Liang4bff3e32014-02-20 18:46:11 +0800823 def restore_active_run_state(self):
824 """Restores active run id and the list of scheduled tests."""
825 self.run_id = self.state_instance.get_shared_data('run_id', optional=True)
826 self.scheduled_run_tests = self.state_instance.get_shared_data(
827 'scheduled_run_tests', optional=True)
828
829 def set_active_run_state(self):
830 """Sets active run id and the list of scheduled tests."""
831 self.run_id = str(uuid.uuid4())
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800832 # try our best to predict which tests will be run.
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800833 self.scheduled_run_tests = self.test_list_iterator.GetPendingTests()
Ricky Liang4bff3e32014-02-20 18:46:11 +0800834 self.state_instance.set_shared_data('run_id', self.run_id)
835 self.state_instance.set_shared_data('scheduled_run_tests',
836 self.scheduled_run_tests)
837
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800838 def run_tests(self, subtree, status_filter=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800839 """Runs tests under subtree.
Jon Salz258a40c2012-04-19 12:34:01 +0800840
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800841 Run tests under a given subtree.
Jon Salzb1b39092012-05-03 02:05:09 +0800842
Ricky Liang6fe218c2013-12-27 15:17:17 +0800843 Args:
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800844 subtree: root of subtree to run or None to run nothing.
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +0800845 status_filter: List of available test states. Only run the tests which
846 states are in the list. Set to None if all test states are available.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800847 """
Hung-Te Lin793d6572017-09-04 18:17:56 +0800848 self.hooks.OnTestStart()
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800849 self.test_list_iterator = TestListIterator(
850 subtree, status_filter, self.test_list)
851 if subtree is not None:
Ricky Liang4bff3e32014-02-20 18:46:11 +0800852 self.set_active_run_state()
Jon Salz0697cbf2012-07-04 15:14:04 +0800853 self.run_next_test()
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800854
Jon Salz0697cbf2012-07-04 15:14:04 +0800855 def reap_completed_tests(self):
Peter Shih0d4f77a2018-01-19 16:15:49 +0800856 """Removes completed tests from the set of active tests."""
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800857 test_completed = False
Peter Shih06d08212018-01-19 17:15:57 +0800858 # Since items are removed while iterating, make a copy using values()
859 # instead of itervalues().
860 for invoc in self.invocations.values():
861 test = invoc.test
862 if invoc.IsCompleted():
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800863 test_completed = True
Peter Shih06d08212018-01-19 17:15:57 +0800864 new_state = test.UpdateState(**invoc.update_state_on_completion)
865 del self.invocations[invoc.uuid]
Jon Salz0697cbf2012-07-04 15:14:04 +0800866
Johny Lin62ed2a32015-05-13 11:57:12 +0800867 # Stop on failure if flag is true and there is no retry chances.
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800868 if (self.test_list.options.stop_on_failure and
Johny Lin62ed2a32015-05-13 11:57:12 +0800869 new_state.retries_left < 0 and
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800870 new_state.status == TestState.FAILED):
871 # Clean all the tests to cause goofy to stop.
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800872 session.console.info('Stop on failure triggered. Empty the queue.')
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800873 self.cancel_pending_tests()
Chun-Ta Lin54e17e42012-09-06 22:05:13 +0800874
Jon Salz1acc8742012-07-17 17:45:55 +0800875 if new_state.iterations_left and new_state.status == TestState.PASSED:
876 # Play it again, Sam!
Peter Shih06d08212018-01-19 17:15:57 +0800877 self._run_test(test)
Cheng-Yi Chiangce05c002013-04-04 02:13:17 +0800878 # new_state.retries_left is obtained after update.
879 # For retries_left == 0, test can still be run for the last time.
880 elif (new_state.retries_left >= 0 and
881 new_state.status == TestState.FAILED):
882 # Still have to retry, Sam!
Peter Shih06d08212018-01-19 17:15:57 +0800883 self._run_test(test)
Jon Salz1acc8742012-07-17 17:45:55 +0800884
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800885 if test_completed:
Vic Yangf01c59f2013-04-19 17:37:56 +0800886 self.log_watcher.KickWatchThread()
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +0800887
Jon Salz6dc031d2013-06-19 13:06:23 +0800888 def kill_active_tests(self, abort, root=None, reason=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800889 """Kills and waits for all active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +0800890
Jon Salz85a39882012-07-05 16:45:04 +0800891 Args:
892 abort: True to change state of killed tests to FAILED, False for
Jon Salz0697cbf2012-07-04 15:14:04 +0800893 UNTESTED.
Jon Salz85a39882012-07-05 16:45:04 +0800894 root: If set, only kills tests with root as an ancestor.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800895 reason: If set, the abort reason.
896 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800897 self.reap_completed_tests()
Peter Shih06d08212018-01-19 17:15:57 +0800898 # Since items are removed while iterating, make a copy using values()
899 # instead of itervalues().
900 for invoc in self.invocations.values():
901 test = invoc.test
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800902 if root and not test.HasAncestor(root):
Jon Salz85a39882012-07-05 16:45:04 +0800903 continue
904
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800905 session.console.info('Killing active test %s...', test.path)
Peter Shih0d4f77a2018-01-19 16:15:49 +0800906 invoc.AbortAndJoin(reason)
Hung-Te Lin03f1fc22017-10-16 16:38:31 +0800907 session.console.info('Killed %s', test.path)
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800908 test.UpdateState(**invoc.update_state_on_completion)
Peter Shih06d08212018-01-19 17:15:57 +0800909 del self.invocations[invoc.uuid]
Jon Salz1acc8742012-07-17 17:45:55 +0800910
Jon Salz0697cbf2012-07-04 15:14:04 +0800911 if not abort:
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800912 test.UpdateState(status=TestState.UNTESTED)
Jon Salz0697cbf2012-07-04 15:14:04 +0800913 self.reap_completed_tests()
914
Jon Salz6dc031d2013-06-19 13:06:23 +0800915 def stop(self, root=None, fail=False, reason=None):
916 self.kill_active_tests(fail, root, reason)
Wei-Han Chenc17b4112016-11-22 14:56:51 +0800917
Wei-Han Chenbcac7252017-04-21 19:46:51 +0800918 self.test_list_iterator.Stop(root)
Jon Salz85a39882012-07-05 16:45:04 +0800919 self.run_next_test()
Jon Salz0697cbf2012-07-04 15:14:04 +0800920
Jon Salz4712ac72013-02-07 17:12:05 +0800921 def clear_state(self, root=None):
Jon Salzd7550792013-07-12 05:49:27 +0800922 if root is None:
923 root = self.test_list
Jon Salz6dc031d2013-06-19 13:06:23 +0800924 self.stop(root, reason='Clearing test state')
Wei-Han Chen3ae204c2017-04-28 19:36:55 +0800925 for f in root.Walk():
926 if f.IsLeaf():
927 f.UpdateState(status=TestState.UNTESTED)
Jon Salz4712ac72013-02-07 17:12:05 +0800928
Jon Salz6dc031d2013-06-19 13:06:23 +0800929 def abort_active_tests(self, reason=None):
930 self.kill_active_tests(True, reason=reason)
Jon Salz0697cbf2012-07-04 15:14:04 +0800931
932 def main(self):
Jon Salzeff94182013-06-19 15:06:28 +0800933 syslog.openlog('goofy')
934
Jon Salz0697cbf2012-07-04 15:14:04 +0800935 try:
Jon Salzd7550792013-07-12 05:49:27 +0800936 self.status = Status.INITIALIZING
Jon Salz0697cbf2012-07-04 15:14:04 +0800937 self.init()
938 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +0800939 success=True)
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800940 testlog.Log(
Joel Kitching9eb203a2016-04-21 15:36:30 +0800941 testlog.StationInit({
Hung-Te Linda8eb992017-09-28 03:27:12 +0800942 'stationDeviceId': session.GetDeviceID(),
943 'stationInstallationId': session.GetInstallationID(),
944 'count': session.GetInitCount(),
Joel Kitching9eb203a2016-04-21 15:36:30 +0800945 'success': True}))
Hung-Te Linc8174b52017-06-02 11:11:45 +0800946 except Exception:
Joel Kitching9eb203a2016-04-21 15:36:30 +0800947 try:
948 if self.event_log:
Jon Salz0697cbf2012-07-04 15:14:04 +0800949 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +0800950 success=False,
951 trace=traceback.format_exc())
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +0800952 if self.testlog:
953 testlog.Log(
Joel Kitching9eb203a2016-04-21 15:36:30 +0800954 testlog.StationInit({
Hung-Te Linda8eb992017-09-28 03:27:12 +0800955 'stationDeviceId': session.GetDeviceID(),
956 'stationInstallationId': session.GetInstallationID(),
957 'count': session.GetInitCount(),
Joel Kitching9eb203a2016-04-21 15:36:30 +0800958 'success': False,
959 'failureMessage': traceback.format_exc()}))
Hung-Te Linc8174b52017-06-02 11:11:45 +0800960 except Exception:
Joel Kitching9eb203a2016-04-21 15:36:30 +0800961 pass
Jon Salz0697cbf2012-07-04 15:14:04 +0800962 raise
963
Jon Salzd7550792013-07-12 05:49:27 +0800964 self.status = Status.RUNNING
Jon Salzeff94182013-06-19 15:06:28 +0800965 syslog.syslog('Goofy (factory test harness) starting')
Chun-Ta Lin5d12b592015-06-30 00:54:23 -0700966 syslog.syslog('Boot sequence = %d' % GetBootSequence())
Hung-Te Linda8eb992017-09-28 03:27:12 +0800967 syslog.syslog('Goofy init count = %d' % session.GetInitCount())
Jon Salz0697cbf2012-07-04 15:14:04 +0800968 self.run()
969
970 def update_system_info(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800971 """Updates system info."""
Shen-En Shihce8ffe02017-08-01 18:58:09 +0800972 logging.info('Received a notify to update system info.')
973 self.dut.info.Invalidate()
974
975 # Propagate this notify to goofy components
976 try:
977 status_monitor = plugin_controller.GetPluginRPCProxy(
978 'status_monitor.status_monitor')
979 status_monitor.UpdateDeviceInfo()
980 except Exception:
981 logging.debug('Failed to update status monitor plugin.')
Jon Salz0697cbf2012-07-04 15:14:04 +0800982
Wei-Han Chen8d7fbc42017-10-18 19:20:47 +0800983 def set_force_auto_run(self):
984 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, FORCE_AUTO_RUN)
985
Jon Salzeb42f0d2012-07-27 19:14:04 +0800986 def update_factory(self, auto_run_on_restart=False, post_update_hook=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800987 """Commences updating factory software.
Jon Salzeb42f0d2012-07-27 19:14:04 +0800988
989 Args:
990 auto_run_on_restart: Auto-run when the machine comes back up.
991 post_update_hook: Code to call after update but immediately before
992 restart.
993
994 Returns:
995 Never if the update was successful (we just reboot).
996 False if the update was unnecessary (no update available).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800997 """
Jon Salz6dc031d2013-06-19 13:06:23 +0800998 self.kill_active_tests(False, reason='Factory software update')
Jon Salza6711d72012-07-18 14:33:03 +0800999 self.cancel_pending_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +08001000
Jon Salz5c344f62012-07-13 14:31:16 +08001001 def pre_update_hook():
1002 if auto_run_on_restart:
Wei-Han Chen8d7fbc42017-10-18 19:20:47 +08001003 self.set_force_auto_run()
Jon Salz5c344f62012-07-13 14:31:16 +08001004 self.state_instance.close()
1005
Jon Salzeb42f0d2012-07-27 19:14:04 +08001006 if updater.TryUpdate(pre_update_hook=pre_update_hook):
1007 if post_update_hook:
1008 post_update_hook()
1009 self.env.shutdown('reboot')
Jon Salz0697cbf2012-07-04 15:14:04 +08001010
chuntsen9d675c62017-06-20 14:35:30 +08001011 def handle_signal(self, signum, unused_frame):
1012 names = [signame for signame in dir(signal) if signame.startswith('SIG') and
1013 getattr(signal, signame) == signum]
1014 signal_name = ', '.join(names) if names else 'UNKNOWN'
1015 logging.error('Received signal %s(%d)', signal_name, signum)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001016 self.run_enqueue(None)
Jon Salz77c151e2012-08-28 07:20:37 +08001017 raise KeyboardInterrupt()
1018
Jon Salz128b0932013-07-03 16:55:26 +08001019 def GetTestList(self, test_list_id):
1020 """Returns the test list with the given ID.
1021
1022 Raises:
1023 TestListError: The test list ID is not valid.
1024 """
1025 try:
1026 return self.test_lists[test_list_id]
1027 except KeyError:
Peter Shihd14623e2017-11-14 15:12:54 +08001028 raise type_utils.TestListError(
Wei-Han Chendbc0fa22017-09-28 10:29:53 +08001029 '%r is not a valid test list ID (available IDs are %r)' % (
1030 test_list_id, sorted(self.test_lists.keys())))
Jon Salz128b0932013-07-03 16:55:26 +08001031
Chih-Yu Huang1725d622017-03-24 16:08:35 +08001032 def _RecordStartError(self, error_message):
1033 """Appends the startup error message into the shared data."""
1034 KEY = 'startup_error'
1035 data = self.state_instance.get_shared_data(KEY, optional=True)
1036 new_data = '%s\n\n%s' % (data, error_message) if data else error_message
1037 self.state_instance.set_shared_data(KEY, new_data)
1038
Jon Salz128b0932013-07-03 16:55:26 +08001039 def InitTestLists(self):
Joel Kitching50a63ea2016-02-22 13:15:09 +08001040 """Reads in all test lists and sets the active test list.
1041
1042 Returns:
1043 True if the active test list could be set, False if failed.
1044 """
1045 startup_errors = []
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +08001046
1047 self.test_lists, failed_files = self.test_list_manager.BuildAllTestLists()
1048
Wei-Han Chendbc0fa22017-09-28 10:29:53 +08001049 logging.info('Loaded test lists: %r', sorted(self.test_lists.keys()))
Jon Salz128b0932013-07-03 16:55:26 +08001050
Joel Kitching50a63ea2016-02-22 13:15:09 +08001051 # Check for any syntax errors in test list files.
1052 if failed_files:
1053 logging.info('Failed test list files: [%s]',
1054 ' '.join(failed_files.keys()))
1055 for f, exc_info in failed_files.iteritems():
1056 logging.error('Error in test list file: %s', f,
1057 exc_info=exc_info)
1058
1059 # Limit the stack trace to the very last entry.
1060 exc_type, exc_value, exc_traceback = exc_info
1061 while exc_traceback and exc_traceback.tb_next:
1062 exc_traceback = exc_traceback.tb_next
1063
1064 exc_string = ''.join(
1065 traceback.format_exception(
1066 exc_type, exc_value, exc_traceback)).rstrip()
1067 startup_errors.append('Error in test list file (%s):\n%s'
1068 % (f, exc_string))
1069
Jon Salz128b0932013-07-03 16:55:26 +08001070 if not self.options.test_list:
Hung-Te Linab78fc42017-09-22 00:21:57 +08001071 self.options.test_list = self.test_list_manager.GetActiveTestListId()
Jon Salz128b0932013-07-03 16:55:26 +08001072
Joel Kitching50a63ea2016-02-22 13:15:09 +08001073 # Check for a non-existent test list ID.
1074 try:
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001075 self.test_list = self.GetTestList(self.options.test_list)
Joel Kitching50a63ea2016-02-22 13:15:09 +08001076 logging.info('Active test list: %s', self.test_list.test_list_id)
Peter Shihd14623e2017-11-14 15:12:54 +08001077 except type_utils.TestListError as e:
Joel Kitching50a63ea2016-02-22 13:15:09 +08001078 logging.exception('Invalid active test list: %s',
1079 self.options.test_list)
1080 startup_errors.append(e.message)
Jon Salz128b0932013-07-03 16:55:26 +08001081
Joel Kitching50a63ea2016-02-22 13:15:09 +08001082 # Show all startup errors.
1083 if startup_errors:
Chih-Yu Huang1725d622017-03-24 16:08:35 +08001084 self._RecordStartError('\n\n'.join(startup_errors))
Joel Kitching50a63ea2016-02-22 13:15:09 +08001085
1086 # Only return False if failed to load the active test list.
1087 return bool(self.test_list)
Jon Salz128b0932013-07-03 16:55:26 +08001088
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001089 def init_hooks(self):
1090 """Initializes hooks.
1091
1092 Must run after self.test_list ready.
1093 """
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001094 module, cls = self.test_list.options.hooks_class.rsplit('.', 1)
1095 self.hooks = getattr(__import__(module, fromlist=[cls]), cls)()
Wei-Han Chen1a114682017-10-02 10:33:54 +08001096 assert isinstance(self.hooks, hooks.Hooks), (
Ricky Liang45c73e72015-01-15 15:00:30 +08001097 'hooks should be of type Hooks but is %r' % type(self.hooks))
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001098 self.hooks.test_list = self.test_list
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001099 self.hooks.OnCreatedTestList()
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001100
Vic Yanga3cecf82014-12-26 00:44:21 -08001101 def init_ui(self):
1102 """Initialize UI."""
Shen-En Shih65619f42017-10-02 16:52:10 +08001103 logging.info('Waiting for a web socket connection')
1104 self.web_socket_manager.wait()
Vic Yanga3cecf82014-12-26 00:44:21 -08001105 self._ui_initialized = True
Vic Yanga3cecf82014-12-26 00:44:21 -08001106
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001107 @staticmethod
1108 def GetCommandLineArgsParser():
1109 """Returns a parser for Goofy command line arguments."""
Jon Salz0697cbf2012-07-04 15:14:04 +08001110 parser = OptionParser()
1111 parser.add_option('-v', '--verbose', dest='verbose',
Jon Salz8fa8e832012-07-13 19:04:09 +08001112 action='store_true',
1113 help='Enable debug logging')
Jon Salz0697cbf2012-07-04 15:14:04 +08001114 parser.add_option('--print_test_list', dest='print_test_list',
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001115 metavar='TEST_LIST_ID',
1116 help='Print the content of TEST_LIST_ID and exit')
Jon Salz0697cbf2012-07-04 15:14:04 +08001117 parser.add_option('--restart', dest='restart',
Jon Salz8fa8e832012-07-13 19:04:09 +08001118 action='store_true',
1119 help='Clear all test state')
Jon Salz0697cbf2012-07-04 15:14:04 +08001120 parser.add_option('--test_list', dest='test_list',
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001121 metavar='TEST_LIST_ID',
1122 help='Use test list whose id is TEST_LIST_ID')
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001123 return parser
1124
Shen-En Shih8227d5d2018-02-06 19:45:39 +08001125 def _PrepareDUTLink(self):
1126 # TODO(akahuang): Move this part into a pytest.
1127 # Prepare DUT link after the plugins start running, because the link might
1128 # need the network connection.
1129
1130 dut_options = self.test_list.options.dut_options
1131 if dut_options:
1132 logging.info('dut_options set by %s: %r', self.test_list.test_list_id,
1133 self.test_list.options.dut_options)
1134
1135 def prepare_link():
1136 try:
1137 device_utils.PrepareDUTLink(**dut_options)
1138 except Exception:
1139 logging.exception('Unable to prepare DUT link.')
1140
1141 thread = threading.Thread(target=prepare_link)
1142 thread.daemon = True
1143 thread.start()
1144
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001145 def init(self, args=None, env=None):
1146 """Initializes Goofy.
1147
1148 Args:
Shen-En Shihe05cbbc2017-10-02 16:47:30 +08001149 args: A list of command-line arguments. Uses sys.argv if args is None.
1150 env: An Environment instance to use (or None to use DUTEnvironment).
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001151 """
1152 (self.options, self.args) = self.GetCommandLineArgsParser().parse_args(args)
Jon Salz0697cbf2012-07-04 15:14:04 +08001153
Joel Kitching261e0422017-03-30 16:52:01 -07001154 signal.signal(signal.SIGINT, self.handle_signal)
1155 signal.signal(signal.SIGTERM, self.handle_signal)
Hung-Te Lina846f602014-07-04 20:32:22 +08001156 # TODO(hungte) SIGTERM does not work properly without Telemetry and should
1157 # be fixed.
Hung-Te Lina846f602014-07-04 20:32:22 +08001158
Jon Salz46b89562012-07-05 11:49:22 +08001159 # Make sure factory directories exist.
Peter Shihb4e49352017-05-25 17:35:11 +08001160 for path in [
1161 paths.DATA_LOG_DIR, paths.DATA_STATE_DIR, paths.DATA_TESTS_DIR]:
1162 file_utils.TryMakeDirs(path)
Jon Salz46b89562012-07-05 11:49:22 +08001163
Wei-Han Chen78f35f62017-03-06 20:11:20 +08001164 try:
1165 goofy_default_options = config_utils.LoadConfig(validate_schema=False)
1166 for key, value in goofy_default_options.iteritems():
1167 if getattr(self.options, key, None) is None:
1168 logging.info('self.options.%s = %r', key, value)
1169 setattr(self.options, key, value)
1170 except Exception:
1171 logging.exception('failed to load goofy overriding options')
1172
Jon Salz0f996602012-10-03 15:26:48 +08001173 if self.options.print_test_list:
Wei-Han Chen16cc5dd2017-04-27 17:38:53 +08001174 all_test_lists, unused_errors = self.test_list_manager.BuildAllTestLists()
1175 test_list = (
1176 all_test_lists[self.options.print_test_list].ToFactoryTestList())
Wei-Han Chen84fee7c2016-08-26 21:56:25 +08001177 print(test_list.__repr__(recursive=True))
Jon Salz0f996602012-10-03 15:26:48 +08001178 sys.exit(0)
1179
Jon Salzee85d522012-07-17 14:34:46 +08001180 event_log.IncrementBootSequence()
Hung-Te Linda8eb992017-09-28 03:27:12 +08001181 session.IncrementInitCount()
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +08001182
Jon Salzd15bbcf2013-05-21 17:33:57 +08001183 # Don't defer logging the initial event, so we can make sure
1184 # that device_id, reimage_id, etc. are all set up.
1185 self.event_log = EventLog('goofy', defer=False)
Chun-Ta Lin53cbbd52016-06-08 21:42:19 +08001186 self.testlog = testlog.Testlog(
Peter Shihb4e49352017-05-25 17:35:11 +08001187 log_root=paths.DATA_LOG_DIR, uuid=self.uuid,
Hung-Te Linda8eb992017-09-28 03:27:12 +08001188 stationDeviceId=session.GetDeviceID(),
1189 stationInstallationId=session.GetInstallationID())
Jon Salz0697cbf2012-07-04 15:14:04 +08001190
Jon Salz0697cbf2012-07-04 15:14:04 +08001191 if env:
1192 self.env = env
Shen-En Shihe05cbbc2017-10-02 16:47:30 +08001193 else:
Ricky Liang09d66d82014-09-25 11:20:54 +08001194 self.env = test_environment.DUTEnvironment()
Jon Salz0697cbf2012-07-04 15:14:04 +08001195 self.env.goofy = self
1196
1197 if self.options.restart:
1198 state.clear_state()
1199
Earl Ouacbe99c2017-02-21 16:04:19 +08001200 self.start_goofy_server()
Peter Shihbb771342017-10-19 16:42:28 +08001201 # The i18n files need to be ready before index.html is loaded.
Peter Shih80e78b42017-03-10 17:00:56 +08001202 self.init_i18n()
Peter Shihbb771342017-10-19 16:42:28 +08001203 self.init_static_files()
1204 self.init_state_instance()
Jon Salz0697cbf2012-07-04 15:14:04 +08001205 self.last_shutdown_time = (
Ricky Liang45c73e72015-01-15 15:00:30 +08001206 self.state_instance.get_shared_data('shutdown_time', optional=True))
Jon Salz0697cbf2012-07-04 15:14:04 +08001207 self.state_instance.del_shared_data('shutdown_time', optional=True)
Jon Salzb19ea072013-02-07 16:35:00 +08001208 self.state_instance.del_shared_data('startup_error', optional=True)
Jon Salz0697cbf2012-07-04 15:14:04 +08001209
Joel Kitching50a63ea2016-02-22 13:15:09 +08001210 success = False
Jon Salz128b0932013-07-03 16:55:26 +08001211 try:
Joel Kitching50a63ea2016-02-22 13:15:09 +08001212 success = self.InitTestLists()
Hung-Te Linc8174b52017-06-02 11:11:45 +08001213 except Exception:
Shen-En Shih44107d12017-10-02 11:31:12 +08001214 logging.exception('Unable to initialize test lists')
1215 self._RecordStartError(
1216 'Unable to initialize test lists\n%s' % traceback.format_exc())
Joel Kitching50a63ea2016-02-22 13:15:09 +08001217
1218 if not success:
Shen-En Shih65619f42017-10-02 16:52:10 +08001219 # Create an empty test list with default options so that the rest of
1220 # startup can proceed.
1221 # A message box will pop up in UI for the error details.
Wei-Han Chena14210e2017-10-16 14:07:52 +08001222 self.test_list = manager.DummyTestList(self.test_list_manager)
1223
1224 self.test_list.state_instance = self.state_instance
Jon Salzb19ea072013-02-07 16:35:00 +08001225
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001226 self.init_hooks()
chuntsen6780ea22017-12-12 14:53:53 +08001227 self.testlog.init_hooks(self.test_list.options.testlog_hooks)
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001228
Jon Salz822838b2013-03-25 17:32:33 +08001229 if self.test_list.options.clear_state_on_start:
1230 self.state_instance.clear_test_state()
1231
Jon Salz670ce062014-05-16 15:53:50 +08001232 # If the phase is invalid, this will raise a ValueError.
1233 phase.SetPersistentPhase(self.test_list.options.phase)
1234
Peter Shih3b0bb9f2017-03-21 16:23:32 +08001235 if not self.state_instance.has_shared_data('ui_locale'):
Hung-Te Lin134403c2017-08-23 17:30:17 +08001236 ui_locale = self.test_list.options.ui_locale
Peter Shih3b0bb9f2017-03-21 16:23:32 +08001237 self.state_instance.set_shared_data('ui_locale', ui_locale)
Jon Salz0697cbf2012-07-04 15:14:04 +08001238 self.state_instance.set_shared_data(
Ricky Liang45c73e72015-01-15 15:00:30 +08001239 'test_list_options',
Peter Shih90425db2017-08-02 15:53:48 +08001240 self.test_list.options.ToDict())
Jon Salz0697cbf2012-07-04 15:14:04 +08001241 self.state_instance.test_list = self.test_list
1242
1243 self.init_states()
1244 self.start_event_server()
Hung-Te Lincc41d2a2014-10-29 13:35:20 +08001245
Earl Oua3bca122016-10-21 16:00:30 +08001246 # Load and run Goofy plugins.
1247 self.plugin_controller = plugin_controller.PluginController(
1248 self.test_list.options.plugin_config_name, self)
1249 self.plugin_controller.StartAllPlugins()
1250
Chih-Yu Huang97103ae2017-03-20 18:22:54 +08001251 if success:
Shen-En Shih8227d5d2018-02-06 19:45:39 +08001252 self._PrepareDUTLink()
Chih-Yu Huang97103ae2017-03-20 18:22:54 +08001253
Jon Salz0697cbf2012-07-04 15:14:04 +08001254 # Note that we create a log watcher even if
1255 # sync_event_log_period_secs isn't set (no background
1256 # syncing), since we may use it to flush event logs as well.
1257 self.log_watcher = EventLogWatcher(
Ricky Liang45c73e72015-01-15 15:00:30 +08001258 self.test_list.options.sync_event_log_period_secs,
1259 event_log_db_file=None,
1260 handle_event_logs_callback=self.handle_event_logs)
Jon Salz0697cbf2012-07-04 15:14:04 +08001261 if self.test_list.options.sync_event_log_period_secs:
1262 self.log_watcher.StartWatchThread()
1263
Shen-En Shihf4ad32f2017-07-31 15:56:39 +08001264 self.event_client.post_event(
1265 Event(Event.Type.UPDATE_SYSTEM_INFO))
Jon Salz0697cbf2012-07-04 15:14:04 +08001266
1267 os.environ['CROS_FACTORY'] = '1'
1268 os.environ['CROS_DISABLE_SITE_SYSINFO'] = '1'
1269
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001270 # Should not move earlier.
1271 self.hooks.OnStartup()
1272
Ricky Liang36512a32014-07-25 11:47:04 +08001273 # Only after this point the Goofy backend is ready for UI connection.
1274 self.ready_for_ui_connection = True
1275
Jon Salz0697cbf2012-07-04 15:14:04 +08001276 def state_change_callback(test, test_state):
1277 self.event_client.post_event(
Peter Shihd46c5fd2017-09-22 15:28:42 +08001278 Event(
1279 Event.Type.STATE_CHANGE,
1280 path=test.path,
1281 state=test_state.ToStruct()))
Jon Salz0697cbf2012-07-04 15:14:04 +08001282 self.test_list.state_change_callback = state_change_callback
Jon Salz73e0fd02012-04-04 11:46:38 +08001283
Vic Yange2c76a82014-10-30 12:48:19 -07001284 self.pytest_prespawner = prespawner.PytestPrespawner()
1285 self.pytest_prespawner.start()
Jon Salza6711d72012-07-18 14:33:03 +08001286
Ricky Liang48e47f92014-02-26 19:31:51 +08001287 tests_after_shutdown = self.state_instance.get_shared_data(
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001288 TESTS_AFTER_SHUTDOWN, optional=True)
Jon Salz5c344f62012-07-13 14:31:16 +08001289 force_auto_run = (tests_after_shutdown == FORCE_AUTO_RUN)
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001290
Jon Salz5c344f62012-07-13 14:31:16 +08001291 if not force_auto_run and tests_after_shutdown is not None:
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001292 logging.info('Resuming tests after shutdown: %r', tests_after_shutdown)
1293 self.test_list_iterator = tests_after_shutdown
Wei-Han Chenbcac7252017-04-21 19:46:51 +08001294 self.test_list_iterator.SetTestList(self.test_list)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001295 self.run_enqueue(self.run_next_test)
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001296 elif force_auto_run or self.test_list.options.auto_run_on_start:
Peter Shih53323922018-01-02 15:02:21 +08001297 status_filter = [TestState.UNTESTED]
1298 if self.test_list.options.retry_failed_on_start:
1299 status_filter.append(TestState.FAILED)
1300 self.run_enqueue(lambda: self.run_tests(self.test_list, status_filter))
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001301 self.state_instance.set_shared_data(TESTS_AFTER_SHUTDOWN, None)
Ricky Liang4bff3e32014-02-20 18:46:11 +08001302 self.restore_active_run_state()
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001303
Hung-Te Lin793d6572017-09-04 18:17:56 +08001304 self.hooks.OnTestStart()
Vic Yang08505c72015-01-06 17:01:53 -08001305
Dean Liao592e4d52013-01-10 20:06:39 +08001306 self.may_disable_cros_shortcut_keys()
1307
1308 def may_disable_cros_shortcut_keys(self):
1309 test_options = self.test_list.options
1310 if test_options.disable_cros_shortcut_keys:
1311 logging.info('Filter ChromeOS shortcut keys.')
1312 self.key_filter = KeyFilter(
1313 unmap_caps_lock=test_options.disable_caps_lock,
1314 caps_lock_keycode=test_options.caps_lock_keycode)
1315 self.key_filter.Start()
1316
Peter Ammon1e1ec572014-06-26 17:56:32 -07001317 def perform_periodic_tasks(self):
Hung-Te Lina452d4d2017-10-25 17:46:14 +08001318 """Perform any periodic work.
Vic Yang4953fc12012-07-26 16:19:53 +08001319
Peter Ammon1e1ec572014-06-26 17:56:32 -07001320 This method must not raise exceptions.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001321 """
Earl Oua3bca122016-10-21 16:00:30 +08001322 self.check_plugins()
cychiang21886742012-07-05 15:16:32 +08001323 self.check_for_updates()
Jon Salz57717ca2012-04-04 16:47:25 +08001324
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001325 def handle_event_logs(self, chunks, periodic=False):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001326 """Callback for event watcher.
Jon Salz258a40c2012-04-19 12:34:01 +08001327
Hung-Te Lind151bf32017-08-30 11:05:47 +08001328 Attempts to upload the event logs to the factory server.
Vic Yang93027612013-05-06 02:42:49 +08001329
1330 Args:
Jon Salzd15bbcf2013-05-21 17:33:57 +08001331 chunks: A list of Chunk objects.
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001332 periodic: This event log handling is periodic. Error messages
1333 will only be shown for the first time.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001334 """
Vic Yang93027612013-05-06 02:42:49 +08001335 first_exception = None
1336 exception_count = 0
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001337 # Suppress error messages for periodic event syncing except for the
1338 # first time. If event syncing is not periodic, always show the error
1339 # messages.
1340 quiet = self._suppress_event_log_error_messages if periodic else False
Vic Yang93027612013-05-06 02:42:49 +08001341
Jon Salzd15bbcf2013-05-21 17:33:57 +08001342 for chunk in chunks:
Vic Yang93027612013-05-06 02:42:49 +08001343 try:
Jon Salzcddb6402013-05-23 12:56:42 +08001344 description = 'event logs (%s)' % str(chunk)
Vic Yang93027612013-05-06 02:42:49 +08001345 start_time = time.time()
Hung-Te Lind151bf32017-08-30 11:05:47 +08001346 proxy = server_proxy.GetServerProxy(quiet=quiet)
1347 proxy.UploadEvent(
1348 chunk.log_name + '.' + event_log.GetReimageId(),
1349 Binary(chunk.chunk))
Vic Yang93027612013-05-06 02:42:49 +08001350 logging.info(
Ricky Liang45c73e72015-01-15 15:00:30 +08001351 'Successfully synced %s in %.03f s',
1352 description, time.time() - start_time)
Hung-Te Linc8174b52017-06-02 11:11:45 +08001353 except Exception:
Hung-Te Linf707b242016-01-08 23:11:42 +08001354 first_exception = (first_exception or
1355 (chunk.log_name + ': ' +
1356 debug_utils.FormatExceptionOnly()))
Vic Yang93027612013-05-06 02:42:49 +08001357 exception_count += 1
1358
1359 if exception_count:
1360 if exception_count == 1:
1361 msg = 'Log upload failed: %s' % first_exception
1362 else:
1363 msg = '%d log upload failed; first is: %s' % (
1364 exception_count, first_exception)
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001365 # For periodic event log syncing, only show the first error messages.
1366 if periodic:
1367 if not self._suppress_event_log_error_messages:
1368 self._suppress_event_log_error_messages = True
Hung-Te Lind151bf32017-08-30 11:05:47 +08001369 logging.warning('Suppress periodic factory server error messages for '
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001370 'event log syncing after the first one.')
1371 raise Exception(msg)
1372 # For event log syncing by request, show the error messages.
1373 else:
1374 raise Exception(msg)
Vic Yang93027612013-05-06 02:42:49 +08001375
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001376 def run_tests_with_status(self, statuses_to_run, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001377 """Runs all top-level tests with a particular status.
Jon Salz0405ab52012-03-16 15:26:52 +08001378
Jon Salz0697cbf2012-07-04 15:14:04 +08001379 All active tests, plus any tests to re-run, are reset.
Jon Salz57717ca2012-04-04 16:47:25 +08001380
Jon Salz0697cbf2012-07-04 15:14:04 +08001381 Args:
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001382 statuses_to_run: The particular status that caller wants to run.
Jon Salz0697cbf2012-07-04 15:14:04 +08001383 starting_at: If provided, only auto-runs tests beginning with
1384 this test.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001385 root: The root of tests to run. If not provided, it will be
1386 the root of all tests.
1387 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001388 root = root or self.test_list
Jon Salz6dc031d2013-06-19 13:06:23 +08001389 self.abort_active_tests('Operator requested run/re-run of certain tests')
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001390 self.run_tests(root, status_filter=statuses_to_run)
Jon Salz0405ab52012-03-16 15:26:52 +08001391
Jon Salz0697cbf2012-07-04 15:14:04 +08001392 def restart_tests(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001393 """Restarts all tests."""
Jon Salz0697cbf2012-07-04 15:14:04 +08001394 root = root or self.test_list
Jon Salz0405ab52012-03-16 15:26:52 +08001395
Jon Salz6dc031d2013-06-19 13:06:23 +08001396 self.abort_active_tests('Operator requested restart of certain tests')
Wei-Han Chen3ae204c2017-04-28 19:36:55 +08001397 for test in root.Walk():
1398 test.UpdateState(status=TestState.UNTESTED)
Jon Salz0697cbf2012-07-04 15:14:04 +08001399 self.run_tests(root)
Hung-Te Lin96632362012-03-20 21:14:18 +08001400
Wei-Han Chenc17b4112016-11-22 14:56:51 +08001401 def auto_run(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001402 """"Auto-runs" tests that have not been run yet.
Hung-Te Lin96632362012-03-20 21:14:18 +08001403
Jon Salz0697cbf2012-07-04 15:14:04 +08001404 Args:
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001405 root: If provided, the root of tests to run. If not provided, the root
1406 will be test_list (root of all tests).
1407 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001408 root = root or self.test_list
1409 self.run_tests_with_status([TestState.UNTESTED, TestState.ACTIVE],
Ricky Liang45c73e72015-01-15 15:00:30 +08001410 root=root)
Jon Salz968e90b2012-03-18 16:12:43 +08001411
Wei-Ning Huang38b75f02015-02-25 18:25:14 +08001412 def handle_key_filter_mode(self, event):
1413 if self.key_filter:
1414 if getattr(event, 'enabled'):
1415 self.key_filter.Start()
1416 else:
1417 self.key_filter.Stop()
1418
Jon Salz0697cbf2012-07-04 15:14:04 +08001419 def wait(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001420 """Waits for all pending invocations.
Jon Salz0697cbf2012-07-04 15:14:04 +08001421
1422 Useful for testing.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001423 """
Jon Salz1acc8742012-07-17 17:45:55 +08001424 while self.invocations:
Peter Shih06d08212018-01-19 17:15:57 +08001425 for invoc in self.invocations.itervalues():
1426 logging.info('Waiting for %s to complete...', invoc.test)
1427 invoc.thread.join()
Jon Salz1acc8742012-07-17 17:45:55 +08001428 self.reap_completed_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +08001429
Claire Changd1961a22015-08-05 16:15:55 +08001430 def test_fail(self, test):
Hung-Te Lin793d6572017-09-04 18:17:56 +08001431 self.hooks.OnTestFailure(test)
Claire Changd1961a22015-08-05 16:15:55 +08001432
Wei-Han Chenced08ef2016-11-08 09:40:02 +08001433
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001434def main():
1435 # Logging should be solved first.
1436 (options, unused_args) = Goofy.GetCommandLineArgsParser().parse_args()
Hung-Te Lin8fc0d652017-09-21 13:05:44 +08001437 log_utils.InitLogging(verbose=options.verbose)
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001438
Peter Ammona3d298c2014-09-23 10:11:02 -07001439 Goofy.run_main_and_exit()
Hung-Te Lin9d81ac72017-09-21 12:58:01 +08001440
1441
1442if __name__ == '__main__':
1443 main()