blob: 9387dd7dc2c0b5343688668b9cf25faa5dc7bda0 [file] [log] [blame]
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001#!/usr/bin/python -u
Hung-Te Linf2f78f72012-02-08 19:27:11 +08002# -*- coding: utf-8 -*-
3#
Jon Salz37eccbd2012-05-25 16:06:52 +08004# Copyright (c) 2012 The Chromium OS Authors. All rights reserved.
Hung-Te Linf2f78f72012-02-08 19:27:11 +08005# Use of this source code is governed by a BSD-style license that can be
6# found in the LICENSE file.
7
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08008"""The main factory flow that runs the factory test and finalizes a device."""
Hung-Te Linf2f78f72012-02-08 19:27:11 +08009
Joel Kitchingb85ed7f2014-10-08 18:24:39 +080010from __future__ import print_function
11
Jon Salze12c2b32013-06-25 16:24:34 +080012import glob
Jon Salz0405ab52012-03-16 15:26:52 +080013import logging
14import os
Jon Salze12c2b32013-06-25 16:24:34 +080015import shutil
Jon Salz77c151e2012-08-28 07:20:37 +080016import signal
Jon Salz0405ab52012-03-16 15:26:52 +080017import sys
Jon Salzeff94182013-06-19 15:06:28 +080018import syslog
Jon Salz0405ab52012-03-16 15:26:52 +080019import threading
20import time
21import traceback
Jon Salz258a40c2012-04-19 12:34:01 +080022import uuid
Jon Salzb10cf512012-08-09 17:29:21 +080023from xmlrpclib import Binary
Hung-Te Linf2f78f72012-02-08 19:27:11 +080024from collections import deque
25from optparse import OptionParser
Hung-Te Linf2f78f72012-02-08 19:27:11 +080026
Jon Salz0697cbf2012-07-04 15:14:04 +080027import factory_common # pylint: disable=W0611
Hung-Te Lin91492a12014-11-25 18:56:30 +080028from cros.factory.test import event_log
jcliangcd688182012-08-20 21:01:26 +080029from cros.factory import system
Hung-Te Lin91492a12014-11-25 18:56:30 +080030from cros.factory.test.event_log import EventLog, FloatDigit
Hung-Te Lincc41d2a2014-10-29 13:35:20 +080031from cros.factory.goofy import connection_manager
Vic Yangd80ea752014-09-24 16:07:14 +080032from cros.factory.goofy import test_environment
33from cros.factory.goofy import time_sanitizer
34from cros.factory.goofy import updater
35from cros.factory.goofy.goofy_base import GoofyBase
36from cros.factory.goofy.goofy_rpc import GoofyRPC
37from cros.factory.goofy.invocation import TestArgEnv
38from cros.factory.goofy.invocation import TestInvocation
39from cros.factory.goofy.link_manager import PresenterLinkManager
Vic Yange2c76a82014-10-30 12:48:19 -070040from cros.factory.goofy import prespawner
Vic Yangd80ea752014-09-24 16:07:14 +080041from cros.factory.goofy.system_log_manager import SystemLogManager
Wei-Ning Huang38b75f02015-02-25 18:25:14 +080042from cros.factory.goofy.terminal_manager import TerminalManager
Vic Yangd80ea752014-09-24 16:07:14 +080043from cros.factory.goofy.web_socket_manager import WebSocketManager
Cheng-Yi Chiangd8186952013-04-04 23:41:14 +080044from cros.factory.system.board import Board, BoardException
jcliangcd688182012-08-20 21:01:26 +080045from cros.factory.system.charge_manager import ChargeManager
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +080046from cros.factory.system.core_dump_manager import CoreDumpManager
Jon Salzce6a7f82013-06-10 18:22:54 +080047from cros.factory.system.cpufreq_manager import CpufreqManager
Jon Salzb92c5112012-09-21 15:40:11 +080048from cros.factory.system import disk_space
jcliangcd688182012-08-20 21:01:26 +080049from cros.factory.test import factory
Jon Salz670ce062014-05-16 15:53:50 +080050from cros.factory.test import phase
jcliangcd688182012-08-20 21:01:26 +080051from cros.factory.test import state
Jon Salz51528e12012-07-02 18:54:45 +080052from cros.factory.test import shopfloor
Jon Salz83591782012-06-26 11:09:58 +080053from cros.factory.test import utils
Jon Salz128b0932013-07-03 16:55:26 +080054from cros.factory.test.test_lists import test_lists
Ricky Liang6fe218c2013-12-27 15:17:17 +080055from cros.factory.test.e2e_test.common import (
56 AutomationMode, AutomationModePrompt, ParseAutomationMode)
Jon Salz83591782012-06-26 11:09:58 +080057from cros.factory.test.event import Event
58from cros.factory.test.event import EventClient
59from cros.factory.test.event import EventServer
Hung-Te Lin91492a12014-11-25 18:56:30 +080060from cros.factory.test.event_log_watcher import EventLogWatcher
jcliangcd688182012-08-20 21:01:26 +080061from cros.factory.test.factory import TestState
Jon Salzd7550792013-07-12 05:49:27 +080062from cros.factory.test.utils import Enum
Dean Liao592e4d52013-01-10 20:06:39 +080063from cros.factory.tools.key_filter import KeyFilter
Jon Salz2af235d2013-06-24 14:47:21 +080064from cros.factory.utils import file_utils
Joel Kitchingb85ed7f2014-10-08 18:24:39 +080065from cros.factory.utils import net_utils
Jon Salz78c32392012-07-25 14:18:29 +080066from cros.factory.utils.process_utils import Spawn
Hung-Te Linf2f78f72012-02-08 19:27:11 +080067
68
Hung-Te Linf2f78f72012-02-08 19:27:11 +080069HWID_CFG_PATH = '/usr/local/share/chromeos-hwid/cfg'
Ricky Liang45c73e72015-01-15 15:00:30 +080070CACHES_DIR = os.path.join(factory.get_state_root(), 'caches')
Hung-Te Linf2f78f72012-02-08 19:27:11 +080071
Cheng-Yi Chiang39d32ad2013-07-23 15:02:38 +080072CLEANUP_LOGS_PAUSED = '/var/lib/cleanup_logs_paused'
73
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
Justin Chuang83813982013-05-13 01:26:32 +080078# Sync disks when battery level is higher than this value.
79# Otherwise, power loss during disk sync operation may incur even worse outcome.
80MIN_BATTERY_LEVEL_FOR_DISK_SYNC = 1.0
81
Ricky Liang45c73e72015-01-15 15:00:30 +080082MAX_CRASH_FILE_SIZE = 64 * 1024
Jon Salze12c2b32013-06-25 16:24:34 +080083
Jon Salzd7550792013-07-12 05:49:27 +080084Status = Enum(['UNINITIALIZED', 'INITIALIZING', 'RUNNING',
85 'TERMINATING', 'TERMINATED'])
86
Ricky Liang45c73e72015-01-15 15:00:30 +080087
Hung-Te Linf2f78f72012-02-08 19:27:11 +080088def get_hwid_cfg():
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +080089 """Returns the HWID config tag, or an empty string if none can be found."""
Jon Salz0697cbf2012-07-04 15:14:04 +080090 if 'CROS_HWID' in os.environ:
91 return os.environ['CROS_HWID']
92 if os.path.exists(HWID_CFG_PATH):
Ricky Liang45c73e72015-01-15 15:00:30 +080093 with open(HWID_CFG_PATH, 'r') as hwid_cfg_handle:
Jon Salz0697cbf2012-07-04 15:14:04 +080094 return hwid_cfg_handle.read().strip()
95 return ''
Hung-Te Linf2f78f72012-02-08 19:27:11 +080096
97
Jon Salz73e0fd02012-04-04 11:46:38 +080098_inited_logging = False
Hung-Te Linf2f78f72012-02-08 19:27:11 +080099
Ricky Liang45c73e72015-01-15 15:00:30 +0800100
Peter Ammon1e1ec572014-06-26 17:56:32 -0700101class Goofy(GoofyBase):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800102 """The main factory flow.
Jon Salz0697cbf2012-07-04 15:14:04 +0800103
104 Note that all methods in this class must be invoked from the main
105 (event) thread. Other threads, such as callbacks and TestInvocation
106 methods, should instead post events on the run queue.
107
108 TODO: Unit tests. (chrome-os-partner:7409)
109
110 Properties:
111 uuid: A unique UUID for this invocation of Goofy.
112 state_instance: An instance of FactoryState.
113 state_server: The FactoryState XML/RPC server.
114 state_server_thread: A thread running state_server.
115 event_server: The EventServer socket server.
116 event_server_thread: A thread running event_server.
117 event_client: A client to the event server.
118 connection_manager: The connection_manager object.
Cheng-Yi Chiang835f2682013-05-06 22:15:48 +0800119 system_log_manager: The SystemLogManager object.
120 core_dump_manager: The CoreDumpManager object.
Jon Salz0697cbf2012-07-04 15:14:04 +0800121 ui_process: The factory ui process object.
Jon Salz0697cbf2012-07-04 15:14:04 +0800122 invocations: A map from FactoryTest objects to the corresponding
123 TestInvocations objects representing active tests.
124 tests_to_run: A deque of tests that should be run when the current
125 test(s) complete.
126 options: Command-line options.
127 args: Command-line args.
128 test_list: The test list.
Jon Salz128b0932013-07-03 16:55:26 +0800129 test_lists: All new-style test lists.
Ricky Liang4bff3e32014-02-20 18:46:11 +0800130 run_id: The identifier for latest test run.
131 scheduled_run_tests: The list of tests scheduled for latest test run.
Jon Salz0697cbf2012-07-04 15:14:04 +0800132 event_handlers: Map of Event.Type to the method used to handle that
133 event. If the method has an 'event' argument, the event is passed
134 to the handler.
Jon Salz3c493bb2013-02-07 17:24:58 +0800135 last_log_disk_space_message: The last message we logged about disk space
136 (to avoid duplication).
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +0800137 last_kick_sync_time: The last time to kick system_log_manager to sync
138 because of core dump files (to avoid kicking too soon then abort the
139 sync.)
Jon Salz416f9cc2013-05-10 18:32:50 +0800140 hooks: A Hooks object containing hooks for various Goofy actions.
Jon Salzd7550792013-07-12 05:49:27 +0800141 status: The current Goofy status (a member of the Status enum).
Peter Ammon948b7172014-07-15 12:43:06 -0700142 link_manager: Instance of PresenterLinkManager for communicating
143 with GoofyPresenter
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800144 """
Ricky Liang45c73e72015-01-15 15:00:30 +0800145
Jon Salz0697cbf2012-07-04 15:14:04 +0800146 def __init__(self):
Peter Ammon1e1ec572014-06-26 17:56:32 -0700147 super(Goofy, self).__init__()
Jon Salz0697cbf2012-07-04 15:14:04 +0800148 self.uuid = str(uuid.uuid4())
149 self.state_instance = None
150 self.state_server = None
151 self.state_server_thread = None
Jon Salz16d10542012-07-23 12:18:45 +0800152 self.goofy_rpc = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800153 self.event_server = None
154 self.event_server_thread = None
155 self.event_client = None
156 self.connection_manager = None
Vic Yang4953fc12012-07-26 16:19:53 +0800157 self.charge_manager = None
Dean Liao88b93192014-10-23 19:37:41 +0800158 self._can_charge = True
Jon Salz8fa8e832012-07-13 19:04:09 +0800159 self.time_sanitizer = None
160 self.time_synced = False
Jon Salz0697cbf2012-07-04 15:14:04 +0800161 self.log_watcher = None
Cheng-Yi Chiang344b10f2013-05-03 16:44:03 +0800162 self.system_log_manager = None
Cheng-Yi Chiang835f2682013-05-06 22:15:48 +0800163 self.core_dump_manager = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800164 self.event_log = None
Vic Yange2c76a82014-10-30 12:48:19 -0700165 self.autotest_prespawner = None
166 self.pytest_prespawner = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800167 self.ui_process = None
Vic Yanga3cecf82014-12-26 00:44:21 -0800168 self._ui_initialized = False
Jon Salzc79a9982012-08-30 04:42:01 +0800169 self.dummy_shopfloor = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800170 self.invocations = {}
171 self.tests_to_run = deque()
172 self.visible_test = None
173 self.chrome = None
Jon Salz416f9cc2013-05-10 18:32:50 +0800174 self.hooks = None
Vic Yangd8990da2013-06-27 16:57:43 +0800175 self.cpu_usage_watcher = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800176
177 self.options = None
178 self.args = None
179 self.test_list = None
Jon Salz128b0932013-07-03 16:55:26 +0800180 self.test_lists = None
Ricky Liang4bff3e32014-02-20 18:46:11 +0800181 self.run_id = None
182 self.scheduled_run_tests = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800183 self.env = None
Jon Salzb22d1172012-08-06 10:38:57 +0800184 self.last_idle = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800185 self.last_shutdown_time = None
cychiang21886742012-07-05 15:16:32 +0800186 self.last_update_check = None
Cheng-Yi Chiang194d3c02015-03-16 14:37:15 +0800187 self._suppress_periodic_update_messages = False
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +0800188 self._suppress_event_log_error_messages = False
Jon Salz8fa8e832012-07-13 19:04:09 +0800189 self.last_sync_time = None
Jon Salzb92c5112012-09-21 15:40:11 +0800190 self.last_log_disk_space_time = None
Jon Salz3c493bb2013-02-07 17:24:58 +0800191 self.last_log_disk_space_message = None
Justin Chuang83813982013-05-13 01:26:32 +0800192 self.last_check_battery_time = None
193 self.last_check_battery_message = None
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +0800194 self.last_kick_sync_time = None
Vic Yang311ddb82012-09-26 12:08:28 +0800195 self.exclusive_items = set()
Jon Salz0f996602012-10-03 15:26:48 +0800196 self.event_log = None
Dean Liao592e4d52013-01-10 20:06:39 +0800197 self.key_filter = None
Jon Salzce6a7f82013-06-10 18:22:54 +0800198 self.cpufreq_manager = None
Jon Salzd7550792013-07-12 05:49:27 +0800199 self.status = Status.UNINITIALIZED
Ricky Liang36512a32014-07-25 11:47:04 +0800200 self.ready_for_ui_connection = False
Peter Ammon1e1ec572014-06-26 17:56:32 -0700201 self.link_manager = None
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800202 self.is_restart_requested = False
Jon Salz0697cbf2012-07-04 15:14:04 +0800203
Jon Salz85a39882012-07-05 16:45:04 +0800204 def test_or_root(event, parent_or_group=True):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800205 """Returns the test affected by a particular event.
Jon Salz85a39882012-07-05 16:45:04 +0800206
207 Args:
208 event: The event containing an optional 'path' attribute.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800209 parent_or_group: If True, returns the top-level parent for a test (the
Jon Salz85a39882012-07-05 16:45:04 +0800210 root node of the tests that need to be run together if the given test
211 path is to be run).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800212 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800213 try:
214 path = event.path
215 except AttributeError:
216 path = None
217
218 if path:
Jon Salz85a39882012-07-05 16:45:04 +0800219 test = self.test_list.lookup_path(path)
220 if parent_or_group:
221 test = test.get_top_level_parent_or_group()
222 return test
Jon Salz0697cbf2012-07-04 15:14:04 +0800223 else:
224 return self.test_list
225
226 self.event_handlers = {
Ricky Liang45c73e72015-01-15 15:00:30 +0800227 Event.Type.SWITCH_TEST: self.handle_switch_test,
228 Event.Type.SHOW_NEXT_ACTIVE_TEST:
229 lambda event: self.show_next_active_test(),
230 Event.Type.RESTART_TESTS:
231 lambda event: self.restart_tests(root=test_or_root(event)),
232 Event.Type.AUTO_RUN:
233 lambda event: self.auto_run(root=test_or_root(event)),
234 Event.Type.RE_RUN_FAILED:
235 lambda event: self.re_run_failed(root=test_or_root(event)),
236 Event.Type.RUN_TESTS_WITH_STATUS:
237 lambda event: self.run_tests_with_status(
238 event.status,
239 root=test_or_root(event)),
240 Event.Type.REVIEW:
241 lambda event: self.show_review_information(),
242 Event.Type.UPDATE_SYSTEM_INFO:
243 lambda event: self.update_system_info(),
244 Event.Type.STOP:
245 lambda event: self.stop(root=test_or_root(event, False),
246 fail=getattr(event, 'fail', False),
247 reason=getattr(event, 'reason', None)),
248 Event.Type.SET_VISIBLE_TEST:
249 lambda event: self.set_visible_test(
250 self.test_list.lookup_path(event.path)),
251 Event.Type.CLEAR_STATE:
252 lambda event: self.clear_state(
253 self.test_list.lookup_path(event.path)),
Wei-Ning Huang38b75f02015-02-25 18:25:14 +0800254 Event.Type.KEY_FILTER_MODE: self.handle_key_filter_mode,
Jon Salz0697cbf2012-07-04 15:14:04 +0800255 }
256
Jon Salz0697cbf2012-07-04 15:14:04 +0800257 self.web_socket_manager = None
Wei-Ning Huang38b75f02015-02-25 18:25:14 +0800258 self.terminal_manager = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800259
260 def destroy(self):
Ricky Liang74237a02014-09-18 15:11:23 +0800261 """Performs any shutdown tasks. Overrides base class method."""
Jon Salzd7550792013-07-12 05:49:27 +0800262 self.status = Status.TERMINATING
Jon Salz0697cbf2012-07-04 15:14:04 +0800263 if self.chrome:
264 self.chrome.kill()
265 self.chrome = None
Jon Salzc79a9982012-08-30 04:42:01 +0800266 if self.dummy_shopfloor:
267 self.dummy_shopfloor.kill()
268 self.dummy_shopfloor = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800269 if self.ui_process:
270 utils.kill_process_tree(self.ui_process, 'ui')
271 self.ui_process = None
272 if self.web_socket_manager:
273 logging.info('Stopping web sockets')
274 self.web_socket_manager.close()
275 self.web_socket_manager = None
276 if self.state_server_thread:
277 logging.info('Stopping state server')
278 self.state_server.shutdown()
279 self.state_server_thread.join()
280 self.state_server.server_close()
281 self.state_server_thread = None
282 if self.state_instance:
283 self.state_instance.close()
284 if self.event_server_thread:
285 logging.info('Stopping event server')
286 self.event_server.shutdown() # pylint: disable=E1101
287 self.event_server_thread.join()
288 self.event_server.server_close()
289 self.event_server_thread = None
290 if self.log_watcher:
291 if self.log_watcher.IsThreadStarted():
292 self.log_watcher.StopWatchThread()
293 self.log_watcher = None
Cheng-Yi Chiang344b10f2013-05-03 16:44:03 +0800294 if self.system_log_manager:
295 if self.system_log_manager.IsThreadRunning():
Cheng-Yi Chianga0f6eff2014-01-09 18:27:22 +0800296 self.system_log_manager.Stop()
Cheng-Yi Chiang344b10f2013-05-03 16:44:03 +0800297 self.system_log_manager = None
Vic Yange2c76a82014-10-30 12:48:19 -0700298 if self.autotest_prespawner:
299 logging.info('Stopping autotest prespawner')
300 self.autotest_prespawner.stop()
301 self.autotest_prespawner = None
302 if self.pytest_prespawner:
303 logging.info('Stopping pytest prespawner')
304 self.pytest_prespawner.stop()
305 self.pytest_prespawner = None
Jon Salz0697cbf2012-07-04 15:14:04 +0800306 if self.event_client:
307 logging.info('Closing event client')
308 self.event_client.close()
309 self.event_client = None
Jon Salzddf0d052013-06-18 12:52:44 +0800310 if self.cpufreq_manager:
311 self.cpufreq_manager.Stop()
Jon Salz0697cbf2012-07-04 15:14:04 +0800312 if self.event_log:
313 self.event_log.Close()
314 self.event_log = None
Dean Liao592e4d52013-01-10 20:06:39 +0800315 if self.key_filter:
316 self.key_filter.Stop()
Vic Yangd8990da2013-06-27 16:57:43 +0800317 if self.cpu_usage_watcher:
318 self.cpu_usage_watcher.terminate()
Peter Ammon1e1ec572014-06-26 17:56:32 -0700319 if self.link_manager:
320 self.link_manager.Stop()
321 self.link_manager = None
Dean Liao592e4d52013-01-10 20:06:39 +0800322
Peter Ammon1e1ec572014-06-26 17:56:32 -0700323 super(Goofy, self).destroy()
Jon Salz0697cbf2012-07-04 15:14:04 +0800324 logging.info('Done destroying Goofy')
Jon Salzd7550792013-07-12 05:49:27 +0800325 self.status = Status.TERMINATED
Jon Salz0697cbf2012-07-04 15:14:04 +0800326
327 def start_state_server(self):
Jon Salz2af235d2013-06-24 14:47:21 +0800328 # Before starting state server, remount stateful partitions with
329 # no commit flag. The default commit time (commit=600) makes corruption
330 # too likely.
Hung-Te Lind59dbfa2014-08-27 12:27:53 +0800331 utils.ResetCommitTime()
Jon Salz2af235d2013-06-24 14:47:21 +0800332
Jon Salz0697cbf2012-07-04 15:14:04 +0800333 self.state_instance, self.state_server = (
Ricky Liang45c73e72015-01-15 15:00:30 +0800334 state.create_server(bind_address='0.0.0.0'))
Jon Salz16d10542012-07-23 12:18:45 +0800335 self.goofy_rpc = GoofyRPC(self)
336 self.goofy_rpc.RegisterMethods(self.state_instance)
Jon Salz0697cbf2012-07-04 15:14:04 +0800337 logging.info('Starting state server')
338 self.state_server_thread = threading.Thread(
Ricky Liang45c73e72015-01-15 15:00:30 +0800339 target=self.state_server.serve_forever,
340 name='StateServer')
Jon Salz0697cbf2012-07-04 15:14:04 +0800341 self.state_server_thread.start()
342
343 def start_event_server(self):
344 self.event_server = EventServer()
345 logging.info('Starting factory event server')
346 self.event_server_thread = threading.Thread(
Ricky Liang45c73e72015-01-15 15:00:30 +0800347 target=self.event_server.serve_forever,
348 name='EventServer') # pylint: disable=E1101
Jon Salz0697cbf2012-07-04 15:14:04 +0800349 self.event_server_thread.start()
350
351 self.event_client = EventClient(
Ricky Liang45c73e72015-01-15 15:00:30 +0800352 callback=self.handle_event, event_loop=self.run_queue)
Jon Salz0697cbf2012-07-04 15:14:04 +0800353
354 self.web_socket_manager = WebSocketManager(self.uuid)
Ricky Liang45c73e72015-01-15 15:00:30 +0800355 self.state_server.add_handler('/event',
356 self.web_socket_manager.handle_web_socket)
Jon Salz0697cbf2012-07-04 15:14:04 +0800357
Wei-Ning Huang38b75f02015-02-25 18:25:14 +0800358 def start_terminal_server(self):
359 self.terminal_manager = TerminalManager()
360 self.state_server.add_handler('/pty',
361 self.terminal_manager.handle_web_socket)
362
Jon Salz0697cbf2012-07-04 15:14:04 +0800363 def start_ui(self):
364 ui_proc_args = [
Ricky Liang45c73e72015-01-15 15:00:30 +0800365 os.path.join(factory.FACTORY_PACKAGE_PATH, 'test', 'ui.py'),
366 self.options.test_list
367 ]
Jon Salz0697cbf2012-07-04 15:14:04 +0800368 if self.options.verbose:
369 ui_proc_args.append('-v')
370 logging.info('Starting ui %s', ui_proc_args)
Jon Salz78c32392012-07-25 14:18:29 +0800371 self.ui_process = Spawn(ui_proc_args)
Jon Salz0697cbf2012-07-04 15:14:04 +0800372 logging.info('Waiting for UI to come up...')
373 self.event_client.wait(
Ricky Liang45c73e72015-01-15 15:00:30 +0800374 lambda event: event.type == Event.Type.UI_READY)
Jon Salz0697cbf2012-07-04 15:14:04 +0800375 logging.info('UI has started')
376
377 def set_visible_test(self, test):
378 if self.visible_test == test:
379 return
Jon Salz2f2d42c2012-07-30 12:30:34 +0800380 if test and not test.has_ui:
381 return
Jon Salz0697cbf2012-07-04 15:14:04 +0800382
383 if test:
384 test.update_state(visible=True)
385 if self.visible_test:
386 self.visible_test.update_state(visible=False)
387 self.visible_test = test
388
Ricky Liang48e47f92014-02-26 19:31:51 +0800389 def log_startup_messages(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800390 """Logs the tail of var/log/messages and mosys and EC console logs."""
Jon Salzd4306c82012-11-30 15:16:36 +0800391 # TODO(jsalz): This is mostly a copy-and-paste of code in init_states,
392 # for factory-3004.B only. Consolidate and merge back to ToT.
393 if utils.in_chroot():
394 return
395
396 try:
Ricky Liang45c73e72015-01-15 15:00:30 +0800397 var_log_messages = utils.var_log_messages_before_reboot()
Jon Salzd4306c82012-11-30 15:16:36 +0800398 logging.info(
Ricky Liang45c73e72015-01-15 15:00:30 +0800399 'Tail of /var/log/messages before last reboot:\n'
400 '%s', ('\n'.join(
401 ' ' + x for x in var_log_messages)))
Jon Salzd4306c82012-11-30 15:16:36 +0800402 except: # pylint: disable=W0702
403 logging.exception('Unable to grok /var/log/messages')
404
405 try:
Ricky Liang117484a2014-04-14 11:14:41 +0800406 mosys_log = Spawn(
Jon Salzd4306c82012-11-30 15:16:36 +0800407 ['mosys', 'eventlog', 'list'],
408 read_stdout=True, log_stderr_on_error=True).stdout_data
409 logging.info('System eventlog from mosys:\n%s\n', mosys_log)
410 except: # pylint: disable=W0702
411 logging.exception('Unable to read mosys eventlog')
412
Dean Liao88b93192014-10-23 19:37:41 +0800413 self.log_ec_console()
414 self.log_ec_panic_info()
415
416 @staticmethod
417 def log_ec_console():
418 """Logs EC console log into logging.info.
419
420 It logs an error message in logging.exception if an exception is raised
421 when getting EC console log.
422 For unsupported device, it logs unsupport message in logging.info
423
424 Returns:
425 EC console log string.
426 """
Jon Salzd4306c82012-11-30 15:16:36 +0800427 try:
Vic Yang8341dde2013-01-29 16:48:52 +0800428 board = system.GetBoard()
429 ec_console_log = board.GetECConsoleLog()
Jon Salzd4306c82012-11-30 15:16:36 +0800430 logging.info('EC console log after reboot:\n%s\n', ec_console_log)
Dean Liao88b93192014-10-23 19:37:41 +0800431 return ec_console_log
432 except NotImplementedError:
433 logging.info('EC console log not supported')
Jon Salzd4306c82012-11-30 15:16:36 +0800434 except: # pylint: disable=W0702
435 logging.exception('Error retrieving EC console log')
436
Dean Liao88b93192014-10-23 19:37:41 +0800437 @staticmethod
438 def log_ec_panic_info():
439 """Logs EC panic info into logging.info.
440
441 It logs an error message in logging.exception if an exception is raised
442 when getting EC panic info.
443 For unsupported device, it logs unsupport message in logging.info
444
445 Returns:
446 EC panic info string.
447 """
Vic Yang079f9872013-07-01 11:32:00 +0800448 try:
449 board = system.GetBoard()
450 ec_panic_info = board.GetECPanicInfo()
451 logging.info('EC panic info after reboot:\n%s\n', ec_panic_info)
Dean Liao88b93192014-10-23 19:37:41 +0800452 return ec_panic_info
453 except NotImplementedError:
454 logging.info('EC panic info is not supported')
Vic Yang079f9872013-07-01 11:32:00 +0800455 except: # pylint: disable=W0702
456 logging.exception('Error retrieving EC panic info')
457
Ricky Liang48e47f92014-02-26 19:31:51 +0800458 def shutdown(self, operation):
459 """Starts shutdown procedure.
460
461 Args:
Vic (Chun-Ju) Yang05b0d952014-04-28 17:39:09 +0800462 operation: The shutdown operation (reboot, full_reboot, or halt).
Ricky Liang48e47f92014-02-26 19:31:51 +0800463 """
464 active_tests = []
465 for test in self.test_list.walk():
466 if not test.is_leaf():
467 continue
468
469 test_state = test.get_state()
470 if test_state.status == TestState.ACTIVE:
471 active_tests.append(test)
472
Ricky Liang48e47f92014-02-26 19:31:51 +0800473 if not (len(active_tests) == 1 and
474 isinstance(active_tests[0], factory.ShutdownStep)):
475 logging.error(
476 'Calling Goofy shutdown outside of the shutdown factory test')
477 return
478
479 logging.info('Start Goofy shutdown (%s)', operation)
480 # Save pending test list in the state server
481 self.state_instance.set_shared_data(
482 'tests_after_shutdown',
483 [t.path for t in self.tests_to_run])
484 # Save shutdown time
485 self.state_instance.set_shared_data('shutdown_time', time.time())
486
487 with self.env.lock:
488 self.event_log.Log('shutdown', operation=operation)
489 shutdown_result = self.env.shutdown(operation)
490 if shutdown_result:
491 # That's all, folks!
Peter Ammon1e1ec572014-06-26 17:56:32 -0700492 self.run_enqueue(None)
Ricky Liang48e47f92014-02-26 19:31:51 +0800493 else:
494 # Just pass (e.g., in the chroot).
495 self.state_instance.set_shared_data('tests_after_shutdown', None)
496 # Send event with no fields to indicate that there is no
497 # longer a pending shutdown.
498 self.event_client.post_event(Event(Event.Type.PENDING_SHUTDOWN))
499
500 def handle_shutdown_complete(self, test):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800501 """Handles the case where a shutdown was detected during a shutdown step.
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800502
Ricky Liang6fe218c2013-12-27 15:17:17 +0800503 Args:
504 test: The ShutdownStep.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800505 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800506 test_state = test.update_state(increment_shutdown_count=1)
507 logging.info('Detected shutdown (%d of %d)',
Ricky Liang48e47f92014-02-26 19:31:51 +0800508 test_state.shutdown_count, test.iterations)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800509
Ricky Liang48e47f92014-02-26 19:31:51 +0800510 # Insert current shutdown test at the front of the list of tests to run
511 # after shutdown. This is to continue on post-shutdown verification in the
512 # shutdown step.
513 tests_after_shutdown = self.state_instance.get_shared_data(
514 'tests_after_shutdown', optional=True)
515 if not tests_after_shutdown:
516 self.state_instance.set_shared_data('tests_after_shutdown', [test.path])
517 elif isinstance(tests_after_shutdown, list):
518 self.state_instance.set_shared_data(
519 'tests_after_shutdown', [test.path] + tests_after_shutdown)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800520
Ricky Liang48e47f92014-02-26 19:31:51 +0800521 # Set 'post_shutdown' to inform shutdown test that a shutdown just occurred.
Ricky Liangb7eb8772014-09-15 18:05:22 +0800522 self.state_instance.set_shared_data(
523 state.POST_SHUTDOWN_TAG % test.path,
524 self.state_instance.get_test_state(test.path).invocation)
Jon Salz258a40c2012-04-19 12:34:01 +0800525
Jon Salz0697cbf2012-07-04 15:14:04 +0800526 def init_states(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800527 """Initializes all states on startup."""
Jon Salz0697cbf2012-07-04 15:14:04 +0800528 for test in self.test_list.get_all_tests():
529 # Make sure the state server knows about all the tests,
530 # defaulting to an untested state.
531 test.update_state(update_parent=False, visible=False)
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800532
Jon Salz0697cbf2012-07-04 15:14:04 +0800533 var_log_messages = None
Vic Yanga9c32212012-08-16 20:07:54 +0800534 mosys_log = None
Vic Yange4c275d2012-08-28 01:50:20 +0800535 ec_console_log = None
Vic Yang079f9872013-07-01 11:32:00 +0800536 ec_panic_info = None
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800537
Jon Salz0697cbf2012-07-04 15:14:04 +0800538 # Any 'active' tests should be marked as failed now.
539 for test in self.test_list.walk():
Jon Salza6711d72012-07-18 14:33:03 +0800540 if not test.is_leaf():
541 # Don't bother with parents; they will be updated when their
542 # children are updated.
543 continue
544
Jon Salz0697cbf2012-07-04 15:14:04 +0800545 test_state = test.get_state()
546 if test_state.status != TestState.ACTIVE:
547 continue
548 if isinstance(test, factory.ShutdownStep):
549 # Shutdown while the test was active - that's good.
Ricky Liang48e47f92014-02-26 19:31:51 +0800550 self.handle_shutdown_complete(test)
Jon Salz0697cbf2012-07-04 15:14:04 +0800551 else:
552 # Unexpected shutdown. Grab /var/log/messages for context.
553 if var_log_messages is None:
554 try:
555 var_log_messages = (
Ricky Liang45c73e72015-01-15 15:00:30 +0800556 utils.var_log_messages_before_reboot())
Jon Salz0697cbf2012-07-04 15:14:04 +0800557 # Write it to the log, to make it easier to
558 # correlate with /var/log/messages.
559 logging.info(
Ricky Liang45c73e72015-01-15 15:00:30 +0800560 'Unexpected shutdown. '
561 'Tail of /var/log/messages before last reboot:\n'
562 '%s', ('\n'.join(
563 ' ' + x for x in var_log_messages)))
Jon Salz0697cbf2012-07-04 15:14:04 +0800564 except: # pylint: disable=W0702
565 logging.exception('Unable to grok /var/log/messages')
566 var_log_messages = []
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800567
Jon Salz008f4ea2012-08-28 05:39:45 +0800568 if mosys_log is None and not utils.in_chroot():
569 try:
Ricky Liang117484a2014-04-14 11:14:41 +0800570 mosys_log = Spawn(
Jon Salz008f4ea2012-08-28 05:39:45 +0800571 ['mosys', 'eventlog', 'list'],
572 read_stdout=True, log_stderr_on_error=True).stdout_data
573 # Write it to the log also.
574 logging.info('System eventlog from mosys:\n%s\n', mosys_log)
575 except: # pylint: disable=W0702
576 logging.exception('Unable to read mosys eventlog')
Vic Yanga9c32212012-08-16 20:07:54 +0800577
Vic Yange4c275d2012-08-28 01:50:20 +0800578 if ec_console_log is None:
Dean Liao88b93192014-10-23 19:37:41 +0800579 ec_console_log = self.log_ec_console()
Vic Yange4c275d2012-08-28 01:50:20 +0800580
Vic Yang079f9872013-07-01 11:32:00 +0800581 if ec_panic_info is None:
Dean Liao88b93192014-10-23 19:37:41 +0800582 ec_panic_info = self.log_ec_panic_info()
Vic Yang079f9872013-07-01 11:32:00 +0800583
Jon Salz0697cbf2012-07-04 15:14:04 +0800584 error_msg = 'Unexpected shutdown while test was running'
585 self.event_log.Log('end_test',
Ricky Liang45c73e72015-01-15 15:00:30 +0800586 path=test.path,
587 status=TestState.FAILED,
588 invocation=test.get_state().invocation,
589 error_msg=error_msg,
590 var_log_messages='\n'.join(var_log_messages),
591 mosys_log=mosys_log)
Jon Salz0697cbf2012-07-04 15:14:04 +0800592 test.update_state(
Ricky Liang45c73e72015-01-15 15:00:30 +0800593 status=TestState.FAILED,
594 error_msg=error_msg)
Chun-Ta Lin87c2dac2015-05-02 01:35:01 -0700595 # Trigger the OnTestFailure callback.
Claire Changd1961a22015-08-05 16:15:55 +0800596 self.run_queue.put(lambda: self.test_fail(test))
Hung-Te Linf2f78f72012-02-08 19:27:11 +0800597
Jon Salz50efe942012-07-26 11:54:10 +0800598 if not test.never_fails:
599 # For "never_fails" tests (such as "Start"), don't cancel
600 # pending tests, since reboot is expected.
601 factory.console.info('Unexpected shutdown while test %s '
602 'running; cancelling any pending tests',
603 test.path)
604 self.state_instance.set_shared_data('tests_after_shutdown', [])
Jon Salz69806bb2012-07-20 18:05:02 +0800605
Jon Salz008f4ea2012-08-28 05:39:45 +0800606 self.update_skipped_tests()
607
608 def update_skipped_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800609 """Updates skipped states based on run_if."""
Jon Salz885dcac2013-07-23 16:39:50 +0800610 env = TestArgEnv()
Ricky Liang45c73e72015-01-15 15:00:30 +0800611
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800612 def _evaluate_skip_from_run_if(test):
613 """Returns the run_if evaluation of the test.
614
615 Args:
616 test: A FactoryTest object.
617
618 Returns:
619 The run_if evaluation result. Returns False if the test has no
620 run_if argument.
621 """
622 value = None
623 if test.run_if_expr:
624 try:
625 value = test.run_if_expr(env)
626 except: # pylint: disable=W0702
627 logging.exception('Unable to evaluate run_if expression for %s',
628 test.path)
629 # But keep going; we have no choice. This will end up
630 # always activating the test.
631 elif test.run_if_table_name:
632 try:
633 aux = shopfloor.get_selected_aux_data(test.run_if_table_name)
634 value = aux.get(test.run_if_col)
635 except ValueError:
636 # Not available; assume it shouldn't be skipped
637 pass
638
639 if value is None:
640 skip = False
641 else:
642 skip = (not value) ^ t.run_if_not
643 return skip
644
645 # Gets all run_if evaluation, and stores results in skip_map.
646 skip_map = dict()
Jon Salz008f4ea2012-08-28 05:39:45 +0800647 for t in self.test_list.walk():
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800648 skip_map[t.path] = _evaluate_skip_from_run_if(t)
Jon Salz885dcac2013-07-23 16:39:50 +0800649
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800650 # Propagates the skip value from root of tree and updates skip_map.
651 def _update_skip_map_from_node(test, skip_from_parent):
652 """Updates skip_map from a given node.
Jon Salz885dcac2013-07-23 16:39:50 +0800653
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800654 Given a FactoryTest node and the skip value from parent, updates the
655 skip value of current node in the skip_map if skip value from parent is
656 True. If this node has children, recursively propagate this value to all
657 its children, that is, all its subtests.
658 Note that this function only updates value in skip_map, not the actual
659 test_list tree.
Jon Salz008f4ea2012-08-28 05:39:45 +0800660
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800661 Args:
662 test: The given FactoryTest object. It is a node in the test_list tree.
663 skip_from_parent: The skip value which propagates from the parent of
664 input node.
665 """
666 skip_this_tree = skip_from_parent or skip_map[test.path]
667 if skip_this_tree:
668 logging.info('Skip from node %r', test.path)
669 skip_map[test.path] = True
670 if test.is_leaf():
671 return
672 # Propagates skip value to its subtests
673 for subtest in test.subtests:
674 _update_skip_map_from_node(subtest, skip_this_tree)
675
676 _update_skip_map_from_node(self.test_list, False)
677
678 # Updates the skip value from skip_map to test_list tree. Also, updates test
679 # status if needed.
680 for t in self.test_list.walk():
681 skip = skip_map[t.path]
682 test_state = t.get_state()
683 if ((not skip) and
684 (test_state.status == TestState.PASSED) and
685 (test_state.error_msg == TestState.SKIPPED_MSG)):
686 # It was marked as skipped before, but now we need to run it.
687 # Mark as untested.
688 t.update_state(skip=skip, status=TestState.UNTESTED, error_msg='')
689 else:
690 t.update_state(skip=skip)
Jon Salz008f4ea2012-08-28 05:39:45 +0800691
Jon Salz0697cbf2012-07-04 15:14:04 +0800692 def show_next_active_test(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800693 """Rotates to the next visible active test."""
Jon Salz0697cbf2012-07-04 15:14:04 +0800694 self.reap_completed_tests()
695 active_tests = [
Ricky Liang45c73e72015-01-15 15:00:30 +0800696 t for t in self.test_list.walk()
697 if t.is_leaf() and t.get_state().status == TestState.ACTIVE]
Jon Salz0697cbf2012-07-04 15:14:04 +0800698 if not active_tests:
699 return
Jon Salz4f6c7172012-06-11 20:45:36 +0800700
Jon Salz0697cbf2012-07-04 15:14:04 +0800701 try:
702 next_test = active_tests[
Ricky Liang45c73e72015-01-15 15:00:30 +0800703 (active_tests.index(self.visible_test) + 1) % len(active_tests)]
Jon Salz0697cbf2012-07-04 15:14:04 +0800704 except ValueError: # visible_test not present in active_tests
705 next_test = active_tests[0]
Jon Salz4f6c7172012-06-11 20:45:36 +0800706
Jon Salz0697cbf2012-07-04 15:14:04 +0800707 self.set_visible_test(next_test)
Jon Salz4f6c7172012-06-11 20:45:36 +0800708
Jon Salz0697cbf2012-07-04 15:14:04 +0800709 def handle_event(self, event):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800710 """Handles an event from the event server."""
Jon Salz0697cbf2012-07-04 15:14:04 +0800711 handler = self.event_handlers.get(event.type)
712 if handler:
713 handler(event)
714 else:
715 # We don't register handlers for all event types - just ignore
716 # this event.
717 logging.debug('Unbound event type %s', event.type)
Jon Salz4f6c7172012-06-11 20:45:36 +0800718
Vic Yangaabf9fd2013-04-09 18:56:13 +0800719 def check_critical_factory_note(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800720 """Returns True if the last factory note is critical."""
Vic Yangaabf9fd2013-04-09 18:56:13 +0800721 notes = self.state_instance.get_shared_data('factory_note', True)
722 return notes and notes[-1]['level'] == 'CRITICAL'
723
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800724 def schedule_restart(self):
725 """Schedules a restart event when any invocation is completed."""
726 self.is_restart_requested = True
727
728 def invocation_completion(self):
729 """Callback when an invocation is completed."""
730 if self.is_restart_requested:
731 logging.info('Restart by scheduled event.')
732 self.is_restart_requested = False
733 self.restart_tests()
734 else:
735 self.run_next_test()
736
Jon Salz0697cbf2012-07-04 15:14:04 +0800737 def run_next_test(self):
henryhsu4cc6b022014-04-22 17:12:42 +0800738 """Runs the next eligible test (or tests) in self.tests_to_run.
739
740 We have three kinds of the next eligible test:
741 1. normal
742 2. backgroundable
743 3. force_background
744
745 And we have four situations of the ongoing invocations:
746 a. only a running normal test
747 b. all running tests are backgroundable
748 c. all running tests are force_background
749 d. all running tests are any combination of backgroundable and
750 force_background
751
752 When a test would like to be run, it must follow the rules:
753 [1] cannot run with [abd]
754 [2] cannot run with [a]
755 All the other combinations are allowed
756 """
Jon Salz0697cbf2012-07-04 15:14:04 +0800757 self.reap_completed_tests()
Vic Yangaabf9fd2013-04-09 18:56:13 +0800758 if self.tests_to_run and self.check_critical_factory_note():
759 self.tests_to_run.clear()
760 return
Jon Salz0697cbf2012-07-04 15:14:04 +0800761 while self.tests_to_run:
Ricky Liang6fe218c2013-12-27 15:17:17 +0800762 logging.debug('Tests to run: %s', [x.path for x in self.tests_to_run])
Jon Salz94eb56f2012-06-12 18:01:12 +0800763
Jon Salz0697cbf2012-07-04 15:14:04 +0800764 test = self.tests_to_run[0]
Jon Salz94eb56f2012-06-12 18:01:12 +0800765
Jon Salz0697cbf2012-07-04 15:14:04 +0800766 if test in self.invocations:
767 logging.info('Next test %s is already running', test.path)
768 self.tests_to_run.popleft()
769 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800770
Jon Salza1412922012-07-23 16:04:17 +0800771 for requirement in test.require_run:
772 for i in requirement.test.walk():
773 if i.get_state().status == TestState.ACTIVE:
Jon Salz304a75d2012-07-06 11:14:15 +0800774 logging.info('Waiting for active test %s to complete '
Jon Salza1412922012-07-23 16:04:17 +0800775 'before running %s', i.path, test.path)
Jon Salz304a75d2012-07-06 11:14:15 +0800776 return
777
henryhsu4cc6b022014-04-22 17:12:42 +0800778 def is_normal_test(test):
779 return not (test.backgroundable or test.force_background)
780
781 # [1] cannot run with [abd].
782 if self.invocations and is_normal_test(test) and any(
783 [not x.force_background for x in self.invocations]):
784 logging.info('Waiting for non-force_background tests to '
785 'complete before running %s', test.path)
786 return
787
788 # [2] cannot run with [a].
789 if self.invocations and test.backgroundable and any(
790 [is_normal_test(x) for x in self.invocations]):
791 logging.info('Waiting for normal tests to '
792 'complete before running %s', test.path)
Jon Salz0697cbf2012-07-04 15:14:04 +0800793 return
Jon Salz94eb56f2012-06-12 18:01:12 +0800794
Jon Salz3e6f5202012-10-15 15:08:29 +0800795 if test.get_state().skip:
796 factory.console.info('Skipping test %s', test.path)
797 test.update_state(status=TestState.PASSED,
798 error_msg=TestState.SKIPPED_MSG)
799 self.tests_to_run.popleft()
800 continue
801
Jon Salz0697cbf2012-07-04 15:14:04 +0800802 self.tests_to_run.popleft()
Jon Salz94eb56f2012-06-12 18:01:12 +0800803
Jon Salz304a75d2012-07-06 11:14:15 +0800804 untested = set()
Jon Salza1412922012-07-23 16:04:17 +0800805 for requirement in test.require_run:
806 for i in requirement.test.walk():
807 if i == test:
Jon Salz304a75d2012-07-06 11:14:15 +0800808 # We've hit this test itself; stop checking
809 break
Jon Salza1412922012-07-23 16:04:17 +0800810 if ((i.get_state().status == TestState.UNTESTED) or
811 (requirement.passed and i.get_state().status !=
812 TestState.PASSED)):
Jon Salz304a75d2012-07-06 11:14:15 +0800813 # Found an untested test; move on to the next
814 # element in require_run.
Jon Salza1412922012-07-23 16:04:17 +0800815 untested.add(i)
Jon Salz304a75d2012-07-06 11:14:15 +0800816 break
817
818 if untested:
819 untested_paths = ', '.join(sorted([x.path for x in untested]))
820 if self.state_instance.get_shared_data('engineering_mode',
821 optional=True):
822 # In engineering mode, we'll let it go.
823 factory.console.warn('In engineering mode; running '
824 '%s even though required tests '
825 '[%s] have not completed',
826 test.path, untested_paths)
827 else:
828 # Not in engineering mode; mark it failed.
829 error_msg = ('Required tests [%s] have not been run yet'
830 % untested_paths)
831 factory.console.error('Not running %s: %s',
832 test.path, error_msg)
833 test.update_state(status=TestState.FAILED,
834 error_msg=error_msg)
835 continue
836
Ricky Liang48e47f92014-02-26 19:31:51 +0800837 if (isinstance(test, factory.ShutdownStep) and
Ricky Liangb7eb8772014-09-15 18:05:22 +0800838 self.state_instance.get_shared_data(
839 state.POST_SHUTDOWN_TAG % test.path, optional=True)):
Ricky Liang48e47f92014-02-26 19:31:51 +0800840 # Invoking post shutdown method of shutdown test. We should retain the
841 # iterations_left and retries_left of the original test state.
842 test_state = self.state_instance.get_test_state(test.path)
843 self._run_test(test, test_state.iterations_left,
844 test_state.retries_left)
845 else:
846 # Starts a new test run; reset iterations and retries.
847 self._run_test(test, test.iterations, test.retries)
Jon Salz1acc8742012-07-17 17:45:55 +0800848
Cheng-Yi Chiangce05c002013-04-04 02:13:17 +0800849 def _run_test(self, test, iterations_left=None, retries_left=None):
Vic Yanga3cecf82014-12-26 00:44:21 -0800850 if not self._ui_initialized and not test.is_no_host():
851 self.init_ui()
Vic Yang08505c72015-01-06 17:01:53 -0800852 invoc = TestInvocation(
Hung-Te Linef7f2be2015-07-20 20:38:51 +0800853 self, test, on_completion=self.invocation_completion,
Claire Changd1961a22015-08-05 16:15:55 +0800854 on_test_failure=lambda: self.test_fail(test))
Jon Salz1acc8742012-07-17 17:45:55 +0800855 new_state = test.update_state(
Ricky Liang48e47f92014-02-26 19:31:51 +0800856 status=TestState.ACTIVE, increment_count=1, error_msg='',
857 invocation=invoc.uuid, iterations_left=iterations_left,
858 retries_left=retries_left,
859 visible=(self.visible_test == test))
Jon Salz1acc8742012-07-17 17:45:55 +0800860 invoc.count = new_state.count
861
862 self.invocations[test] = invoc
863 if self.visible_test is None and test.has_ui:
864 self.set_visible_test(test)
Vic Yang311ddb82012-09-26 12:08:28 +0800865 self.check_exclusive()
Jon Salz1acc8742012-07-17 17:45:55 +0800866 invoc.start()
Jon Salz5f2a0672012-05-22 17:14:06 +0800867
Vic Yang311ddb82012-09-26 12:08:28 +0800868 def check_exclusive(self):
Jon Salzce6a7f82013-06-10 18:22:54 +0800869 # alias since this is really long
870 EXCL_OPT = factory.FactoryTest.EXCLUSIVE_OPTIONS
871
Vic Yang311ddb82012-09-26 12:08:28 +0800872 current_exclusive_items = set([
Jon Salzce6a7f82013-06-10 18:22:54 +0800873 item for item in EXCL_OPT
Vic Yang311ddb82012-09-26 12:08:28 +0800874 if any([test.is_exclusive(item) for test in self.invocations])])
875
876 new_exclusive_items = current_exclusive_items - self.exclusive_items
Jon Salzce6a7f82013-06-10 18:22:54 +0800877 if EXCL_OPT.NETWORKING in new_exclusive_items:
Vic Yang311ddb82012-09-26 12:08:28 +0800878 logging.info('Disabling network')
879 self.connection_manager.DisableNetworking()
Jon Salzce6a7f82013-06-10 18:22:54 +0800880 if EXCL_OPT.CHARGER in new_exclusive_items:
Vic Yang311ddb82012-09-26 12:08:28 +0800881 logging.info('Stop controlling charger')
882
883 new_non_exclusive_items = self.exclusive_items - current_exclusive_items
Jon Salzce6a7f82013-06-10 18:22:54 +0800884 if EXCL_OPT.NETWORKING in new_non_exclusive_items:
Vic Yang311ddb82012-09-26 12:08:28 +0800885 logging.info('Re-enabling network')
886 self.connection_manager.EnableNetworking()
Jon Salzce6a7f82013-06-10 18:22:54 +0800887 if EXCL_OPT.CHARGER in new_non_exclusive_items:
Vic Yang311ddb82012-09-26 12:08:28 +0800888 logging.info('Start controlling charger')
889
Jon Salzce6a7f82013-06-10 18:22:54 +0800890 if self.cpufreq_manager:
891 enabled = EXCL_OPT.CPUFREQ not in current_exclusive_items
892 try:
893 self.cpufreq_manager.SetEnabled(enabled)
894 except: # pylint: disable=W0702
895 logging.exception('Unable to %s cpufreq services',
896 'enable' if enabled else 'disable')
897
Ricky Liang0f9978e2015-01-30 08:19:17 +0000898 # Only adjust charge state if not excluded
899 if (EXCL_OPT.CHARGER not in current_exclusive_items and
900 not utils.in_chroot()):
901 if self.charge_manager:
Cheng-Yi Chiangd8186952013-04-04 23:41:14 +0800902 self.charge_manager.AdjustChargeState()
903 else:
Dean Liao88b93192014-10-23 19:37:41 +0800904 self.charge()
Vic Yang311ddb82012-09-26 12:08:28 +0800905
906 self.exclusive_items = current_exclusive_items
Jon Salz5da61e62012-05-31 13:06:22 +0800907
Dean Liao88b93192014-10-23 19:37:41 +0800908 def charge(self):
909 """Charges the board.
910
911 It won't try again if last time SetChargeState raised an exception.
912 """
913 if not self._can_charge:
914 return
915
916 try:
Ricky Liang9ac35e02015-01-30 16:01:32 +0800917 if self.charge_manager:
918 self.charge_manager.StartCharging()
919 else:
920 system.GetBoard().SetChargeState(Board.ChargeState.CHARGE)
Dean Liao88b93192014-10-23 19:37:41 +0800921 except NotImplementedError:
922 logging.info('Charging is not supported')
923 self._can_charge = False
924 except BoardException:
925 logging.exception('Unable to set charge state on this board')
926 self._can_charge = False
927
cychiang21886742012-07-05 15:16:32 +0800928 def check_for_updates(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800929 """Schedules an asynchronous check for updates if necessary."""
cychiang21886742012-07-05 15:16:32 +0800930 if not self.test_list.options.update_period_secs:
931 # Not enabled.
932 return
933
934 now = time.time()
935 if self.last_update_check and (
936 now - self.last_update_check <
937 self.test_list.options.update_period_secs):
938 # Not yet time for another check.
939 return
940
941 self.last_update_check = now
942
943 def handle_check_for_update(reached_shopfloor, md5sum, needs_update):
944 if reached_shopfloor:
945 new_update_md5sum = md5sum if needs_update else None
946 if system.SystemInfo.update_md5sum != new_update_md5sum:
947 logging.info('Received new update MD5SUM: %s', new_update_md5sum)
948 system.SystemInfo.update_md5sum = new_update_md5sum
Peter Ammon1e1ec572014-06-26 17:56:32 -0700949 self.run_enqueue(self.update_system_info)
Cheng-Yi Chiang194d3c02015-03-16 14:37:15 +0800950 else:
951 if not self._suppress_periodic_update_messages:
952 logging.warning('Suppress error messages for periodic update checking'
953 ' after the first one.')
954 self._suppress_periodic_update_messages = True
cychiang21886742012-07-05 15:16:32 +0800955
956 updater.CheckForUpdateAsync(
Ricky Liang45c73e72015-01-15 15:00:30 +0800957 handle_check_for_update,
Cheng-Yi Chiang194d3c02015-03-16 14:37:15 +0800958 self.test_list.options.shopfloor_timeout_secs,
959 self._suppress_periodic_update_messages)
cychiang21886742012-07-05 15:16:32 +0800960
Jon Salza6711d72012-07-18 14:33:03 +0800961 def cancel_pending_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800962 """Cancels any tests in the run queue."""
Jon Salza6711d72012-07-18 14:33:03 +0800963 self.run_tests([])
964
Ricky Liang4bff3e32014-02-20 18:46:11 +0800965 def restore_active_run_state(self):
966 """Restores active run id and the list of scheduled tests."""
967 self.run_id = self.state_instance.get_shared_data('run_id', optional=True)
968 self.scheduled_run_tests = self.state_instance.get_shared_data(
969 'scheduled_run_tests', optional=True)
970
971 def set_active_run_state(self):
972 """Sets active run id and the list of scheduled tests."""
973 self.run_id = str(uuid.uuid4())
974 self.scheduled_run_tests = [test.path for test in self.tests_to_run]
975 self.state_instance.set_shared_data('run_id', self.run_id)
976 self.state_instance.set_shared_data('scheduled_run_tests',
977 self.scheduled_run_tests)
978
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +0800979 def run_tests(self, subtrees, status_filter=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800980 """Runs tests under subtree.
Jon Salz258a40c2012-04-19 12:34:01 +0800981
Jon Salz0697cbf2012-07-04 15:14:04 +0800982 The tests are run in order unless one fails (then stops).
983 Backgroundable tests are run simultaneously; when a foreground test is
984 encountered, we wait for all active tests to finish before continuing.
Jon Salzb1b39092012-05-03 02:05:09 +0800985
Ricky Liang6fe218c2013-12-27 15:17:17 +0800986 Args:
987 subtrees: Node or nodes containing tests to run (may either be
988 a single test or a list). Duplicates will be ignored.
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +0800989 status_filter: List of available test states. Only run the tests which
990 states are in the list. Set to None if all test states are available.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +0800991 """
Vic Yang08505c72015-01-06 17:01:53 -0800992 system.GetBoard().OnTestStart()
993
Jon Salz0697cbf2012-07-04 15:14:04 +0800994 if type(subtrees) != list:
995 subtrees = [subtrees]
Jon Salz258a40c2012-04-19 12:34:01 +0800996
Jon Salz0697cbf2012-07-04 15:14:04 +0800997 # Nodes we've seen so far, to avoid duplicates.
998 seen = set()
Jon Salz94eb56f2012-06-12 18:01:12 +0800999
Jon Salz0697cbf2012-07-04 15:14:04 +08001000 self.tests_to_run = deque()
1001 for subtree in subtrees:
1002 for test in subtree.walk():
1003 if test in seen:
1004 continue
1005 seen.add(test)
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001006
Jon Salz0697cbf2012-07-04 15:14:04 +08001007 if not test.is_leaf():
1008 continue
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +08001009 if (status_filter is not None and
1010 test.get_state().status not in status_filter):
Jon Salz0697cbf2012-07-04 15:14:04 +08001011 continue
1012 self.tests_to_run.append(test)
Ricky Liang4bff3e32014-02-20 18:46:11 +08001013 if subtrees:
1014 self.set_active_run_state()
Jon Salz0697cbf2012-07-04 15:14:04 +08001015 self.run_next_test()
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001016
Jon Salz0697cbf2012-07-04 15:14:04 +08001017 def reap_completed_tests(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001018 """Removes completed tests from the set of active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +08001019
1020 Also updates the visible test if it was reaped.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001021 """
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +08001022 test_completed = False
Jon Salz0697cbf2012-07-04 15:14:04 +08001023 for t, v in dict(self.invocations).iteritems():
1024 if v.is_completed():
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +08001025 test_completed = True
Jon Salz1acc8742012-07-17 17:45:55 +08001026 new_state = t.update_state(**v.update_state_on_completion)
Jon Salz0697cbf2012-07-04 15:14:04 +08001027 del self.invocations[t]
1028
Johny Lin62ed2a32015-05-13 11:57:12 +08001029 # Stop on failure if flag is true and there is no retry chances.
Chun-Ta Lin54e17e42012-09-06 22:05:13 +08001030 if (self.test_list.options.stop_on_failure and
Johny Lin62ed2a32015-05-13 11:57:12 +08001031 new_state.retries_left < 0 and
Chun-Ta Lin54e17e42012-09-06 22:05:13 +08001032 new_state.status == TestState.FAILED):
1033 # Clean all the tests to cause goofy to stop.
1034 self.tests_to_run = []
Ricky Liang45c73e72015-01-15 15:00:30 +08001035 factory.console.info('Stop on failure triggered. Empty the queue.')
Chun-Ta Lin54e17e42012-09-06 22:05:13 +08001036
Jon Salz1acc8742012-07-17 17:45:55 +08001037 if new_state.iterations_left and new_state.status == TestState.PASSED:
1038 # Play it again, Sam!
1039 self._run_test(t)
Cheng-Yi Chiangce05c002013-04-04 02:13:17 +08001040 # new_state.retries_left is obtained after update.
1041 # For retries_left == 0, test can still be run for the last time.
1042 elif (new_state.retries_left >= 0 and
1043 new_state.status == TestState.FAILED):
1044 # Still have to retry, Sam!
1045 self._run_test(t)
Jon Salz1acc8742012-07-17 17:45:55 +08001046
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +08001047 if test_completed:
Vic Yangf01c59f2013-04-19 17:37:56 +08001048 self.log_watcher.KickWatchThread()
Cheng-Yi Chiang5ac22ca2013-04-12 17:45:26 +08001049
Jon Salz0697cbf2012-07-04 15:14:04 +08001050 if (self.visible_test is None or
Jon Salz85a39882012-07-05 16:45:04 +08001051 self.visible_test not in self.invocations):
Jon Salz0697cbf2012-07-04 15:14:04 +08001052 self.set_visible_test(None)
1053 # Make the first running test, if any, the visible test
1054 for t in self.test_list.walk():
1055 if t in self.invocations:
1056 self.set_visible_test(t)
1057 break
1058
Jon Salz6dc031d2013-06-19 13:06:23 +08001059 def kill_active_tests(self, abort, root=None, reason=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001060 """Kills and waits for all active tests.
Jon Salz0697cbf2012-07-04 15:14:04 +08001061
Jon Salz85a39882012-07-05 16:45:04 +08001062 Args:
1063 abort: True to change state of killed tests to FAILED, False for
Jon Salz0697cbf2012-07-04 15:14:04 +08001064 UNTESTED.
Jon Salz85a39882012-07-05 16:45:04 +08001065 root: If set, only kills tests with root as an ancestor.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001066 reason: If set, the abort reason.
1067 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001068 self.reap_completed_tests()
1069 for test, invoc in self.invocations.items():
Jon Salz85a39882012-07-05 16:45:04 +08001070 if root and not test.has_ancestor(root):
1071 continue
1072
Ricky Liang45c73e72015-01-15 15:00:30 +08001073 factory.console.info('Killing active test %s...', test.path)
Jon Salz6dc031d2013-06-19 13:06:23 +08001074 invoc.abort_and_join(reason)
Ricky Liang45c73e72015-01-15 15:00:30 +08001075 factory.console.info('Killed %s', test.path)
Jon Salz1acc8742012-07-17 17:45:55 +08001076 test.update_state(**invoc.update_state_on_completion)
Jon Salz0697cbf2012-07-04 15:14:04 +08001077 del self.invocations[test]
Jon Salz1acc8742012-07-17 17:45:55 +08001078
Jon Salz0697cbf2012-07-04 15:14:04 +08001079 if not abort:
1080 test.update_state(status=TestState.UNTESTED)
1081 self.reap_completed_tests()
1082
Jon Salz6dc031d2013-06-19 13:06:23 +08001083 def stop(self, root=None, fail=False, reason=None):
1084 self.kill_active_tests(fail, root, reason)
Jon Salz85a39882012-07-05 16:45:04 +08001085 # Remove any tests in the run queue under the root.
1086 self.tests_to_run = deque([x for x in self.tests_to_run
1087 if root and not x.has_ancestor(root)])
1088 self.run_next_test()
Jon Salz0697cbf2012-07-04 15:14:04 +08001089
Jon Salz4712ac72013-02-07 17:12:05 +08001090 def clear_state(self, root=None):
Jon Salzd7550792013-07-12 05:49:27 +08001091 if root is None:
1092 root = self.test_list
Jon Salz6dc031d2013-06-19 13:06:23 +08001093 self.stop(root, reason='Clearing test state')
Jon Salz4712ac72013-02-07 17:12:05 +08001094 for f in root.walk():
1095 if f.is_leaf():
1096 f.update_state(status=TestState.UNTESTED)
1097
Jon Salz6dc031d2013-06-19 13:06:23 +08001098 def abort_active_tests(self, reason=None):
1099 self.kill_active_tests(True, reason=reason)
Jon Salz0697cbf2012-07-04 15:14:04 +08001100
1101 def main(self):
Jon Salzeff94182013-06-19 15:06:28 +08001102 syslog.openlog('goofy')
1103
Jon Salz0697cbf2012-07-04 15:14:04 +08001104 try:
Jon Salzd7550792013-07-12 05:49:27 +08001105 self.status = Status.INITIALIZING
Jon Salz0697cbf2012-07-04 15:14:04 +08001106 self.init()
1107 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +08001108 success=True)
Jon Salz0697cbf2012-07-04 15:14:04 +08001109 except:
1110 if self.event_log:
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001111 try:
Jon Salz0697cbf2012-07-04 15:14:04 +08001112 self.event_log.Log('goofy_init',
Ricky Liang45c73e72015-01-15 15:00:30 +08001113 success=False,
1114 trace=traceback.format_exc())
Jon Salz0697cbf2012-07-04 15:14:04 +08001115 except: # pylint: disable=W0702
1116 pass
1117 raise
1118
Jon Salzd7550792013-07-12 05:49:27 +08001119 self.status = Status.RUNNING
Jon Salzeff94182013-06-19 15:06:28 +08001120 syslog.syslog('Goofy (factory test harness) starting')
Jon Salz0697cbf2012-07-04 15:14:04 +08001121 self.run()
1122
1123 def update_system_info(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001124 """Updates system info."""
Jon Salz0697cbf2012-07-04 15:14:04 +08001125 system_info = system.SystemInfo()
1126 self.state_instance.set_shared_data('system_info', system_info.__dict__)
1127 self.event_client.post_event(Event(Event.Type.SYSTEM_INFO,
Ricky Liang45c73e72015-01-15 15:00:30 +08001128 system_info=system_info.__dict__))
Jon Salz0697cbf2012-07-04 15:14:04 +08001129 logging.info('System info: %r', system_info.__dict__)
1130
Jon Salzeb42f0d2012-07-27 19:14:04 +08001131 def update_factory(self, auto_run_on_restart=False, post_update_hook=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001132 """Commences updating factory software.
Jon Salzeb42f0d2012-07-27 19:14:04 +08001133
1134 Args:
1135 auto_run_on_restart: Auto-run when the machine comes back up.
1136 post_update_hook: Code to call after update but immediately before
1137 restart.
1138
1139 Returns:
1140 Never if the update was successful (we just reboot).
1141 False if the update was unnecessary (no update available).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001142 """
Jon Salz6dc031d2013-06-19 13:06:23 +08001143 self.kill_active_tests(False, reason='Factory software update')
Jon Salza6711d72012-07-18 14:33:03 +08001144 self.cancel_pending_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +08001145
Jon Salz5c344f62012-07-13 14:31:16 +08001146 def pre_update_hook():
1147 if auto_run_on_restart:
1148 self.state_instance.set_shared_data('tests_after_shutdown',
1149 FORCE_AUTO_RUN)
1150 self.state_instance.close()
1151
Jon Salzeb42f0d2012-07-27 19:14:04 +08001152 if updater.TryUpdate(pre_update_hook=pre_update_hook):
1153 if post_update_hook:
1154 post_update_hook()
1155 self.env.shutdown('reboot')
Jon Salz0697cbf2012-07-04 15:14:04 +08001156
Ricky Liang8fecf412014-05-22 10:56:14 +08001157 def handle_sigint(self, dummy_signum, dummy_frame): # pylint: disable=W0613
Jon Salz77c151e2012-08-28 07:20:37 +08001158 logging.error('Received SIGINT')
Peter Ammon1e1ec572014-06-26 17:56:32 -07001159 self.run_enqueue(None)
Jon Salz77c151e2012-08-28 07:20:37 +08001160 raise KeyboardInterrupt()
1161
Ricky Liang8fecf412014-05-22 10:56:14 +08001162 def handle_sigterm(self, dummy_signum, dummy_frame): # pylint: disable=W0613
1163 logging.error('Received SIGTERM')
Hung-Te Lin94ca4742014-07-09 20:13:50 +08001164 self.env.terminate()
1165 self.run_queue.put(None)
Ricky Liang8fecf412014-05-22 10:56:14 +08001166 raise RuntimeError('Received SIGTERM')
1167
Jon Salze12c2b32013-06-25 16:24:34 +08001168 def find_kcrashes(self):
1169 """Finds kcrash files, logs them, and marks them as seen."""
1170 seen_crashes = set(
1171 self.state_instance.get_shared_data('seen_crashes', optional=True)
1172 or [])
1173
1174 for path in glob.glob('/var/spool/crash/*'):
1175 if not os.path.isfile(path):
1176 continue
1177 if path in seen_crashes:
1178 continue
1179 try:
1180 stat = os.stat(path)
1181 mtime = utils.TimeString(stat.st_mtime)
1182 logging.info(
1183 'Found new crash file %s (%d bytes at %s)',
1184 path, stat.st_size, mtime)
1185 extra_log_args = {}
1186
1187 try:
1188 _, ext = os.path.splitext(path)
1189 if ext in ['.kcrash', '.meta']:
1190 ext = ext.replace('.', '')
1191 with open(path) as f:
1192 data = f.read(MAX_CRASH_FILE_SIZE)
1193 tell = f.tell()
1194 logging.info(
1195 'Contents of %s%s:%s',
1196 path,
1197 ('' if tell == stat.st_size
1198 else '(truncated to %d bytes)' % MAX_CRASH_FILE_SIZE),
1199 ('\n' + data).replace('\n', '\n ' + ext + '> '))
1200 extra_log_args['data'] = data
1201
1202 # Copy to /var/factory/kcrash for posterity
1203 kcrash_dir = factory.get_factory_root('kcrash')
1204 utils.TryMakeDirs(kcrash_dir)
1205 shutil.copy(path, kcrash_dir)
1206 logging.info('Copied to %s',
1207 os.path.join(kcrash_dir, os.path.basename(path)))
1208 finally:
1209 # Even if something goes wrong with the above, still try to
1210 # log to event log
1211 self.event_log.Log('crash_file',
1212 path=path, size=stat.st_size, mtime=mtime,
1213 **extra_log_args)
1214 except: # pylint: disable=W0702
1215 logging.exception('Unable to handle crash files %s', path)
1216 seen_crashes.add(path)
1217
1218 self.state_instance.set_shared_data('seen_crashes', list(seen_crashes))
1219
Jon Salz128b0932013-07-03 16:55:26 +08001220 def GetTestList(self, test_list_id):
1221 """Returns the test list with the given ID.
1222
1223 Raises:
1224 TestListError: The test list ID is not valid.
1225 """
1226 try:
1227 return self.test_lists[test_list_id]
1228 except KeyError:
1229 raise test_lists.TestListError(
1230 '%r is not a valid test list ID (available IDs are [%s])' % (
1231 test_list_id, ', '.join(sorted(self.test_lists.keys()))))
1232
1233 def InitTestLists(self):
1234 """Reads in all test lists and sets the active test list."""
Ricky Liang27051552014-05-04 14:22:26 +08001235 self.test_lists = test_lists.BuildAllTestLists(
1236 force_generic=(self.options.automation_mode is not None))
Jon Salzd7550792013-07-12 05:49:27 +08001237 logging.info('Loaded test lists: [%s]',
1238 test_lists.DescribeTestLists(self.test_lists))
Jon Salz128b0932013-07-03 16:55:26 +08001239
1240 if not self.options.test_list:
1241 self.options.test_list = test_lists.GetActiveTestListId()
1242
1243 if os.sep in self.options.test_list:
1244 # It's a path pointing to an old-style test list; use it.
1245 self.test_list = factory.read_test_list(self.options.test_list)
1246 else:
1247 self.test_list = self.GetTestList(self.options.test_list)
1248
1249 logging.info('Active test list: %s', self.test_list.test_list_id)
1250
1251 if isinstance(self.test_list, test_lists.OldStyleTestList):
1252 # Actually load it in. (See OldStyleTestList for an explanation
1253 # of why this is necessary.)
1254 self.test_list = self.test_list.Load()
1255
1256 self.test_list.state_instance = self.state_instance
1257
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001258 def init_hooks(self):
1259 """Initializes hooks.
1260
1261 Must run after self.test_list ready.
1262 """
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001263 module, cls = self.test_list.options.hooks_class.rsplit('.', 1)
1264 self.hooks = getattr(__import__(module, fromlist=[cls]), cls)()
1265 assert isinstance(self.hooks, factory.Hooks), (
Ricky Liang45c73e72015-01-15 15:00:30 +08001266 'hooks should be of type Hooks but is %r' % type(self.hooks))
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001267 self.hooks.test_list = self.test_list
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001268 self.hooks.OnCreatedTestList()
Shuo-Peng Liao52b90da2013-06-30 17:00:06 +08001269
Vic Yanga3cecf82014-12-26 00:44:21 -08001270 def init_ui(self):
1271 """Initialize UI."""
1272 self._ui_initialized = True
1273 if self.options.ui == 'chrome':
Hung-Te Lin8f6a3782015-01-06 22:58:32 +08001274 if self.options.monolithic:
Hung-Te Lin7bd55312014-12-30 16:43:36 +08001275 self.env.launch_chrome()
1276 else:
1277 # The presenter is responsible for launching Chrome. Let's just
1278 # wait here.
1279 self.env.controller_ready_for_ui()
Vic Yanga3cecf82014-12-26 00:44:21 -08001280 logging.info('Waiting for a web socket connection')
1281 self.web_socket_manager.wait()
1282
1283 # Wait for the test widget size to be set; this is done in
1284 # an asynchronous RPC so there is a small chance that the
1285 # web socket might be opened first.
1286 for _ in range(100): # 10 s
1287 try:
1288 if self.state_instance.get_shared_data('test_widget_size'):
1289 break
1290 except KeyError:
1291 pass # Retry
1292 time.sleep(0.1) # 100 ms
1293 else:
1294 logging.warn('Never received test_widget_size from UI')
1295
Hung-Te Lin7bd55312014-12-30 16:43:36 +08001296 logging.info('Waiting for a web socket connection')
1297 self.web_socket_manager.wait()
1298
Jon Salz0697cbf2012-07-04 15:14:04 +08001299 def init(self, args=None, env=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001300 """Initializes Goofy.
Jon Salz0697cbf2012-07-04 15:14:04 +08001301
1302 Args:
1303 args: A list of command-line arguments. Uses sys.argv if
1304 args is None.
1305 env: An Environment instance to use (or None to choose
1306 FakeChrootEnvironment or DUTEnvironment as appropriate).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001307 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001308 parser = OptionParser()
1309 parser.add_option('-v', '--verbose', dest='verbose',
Jon Salz8fa8e832012-07-13 19:04:09 +08001310 action='store_true',
1311 help='Enable debug logging')
Jon Salz0697cbf2012-07-04 15:14:04 +08001312 parser.add_option('--print_test_list', dest='print_test_list',
Jon Salz8fa8e832012-07-13 19:04:09 +08001313 metavar='FILE',
1314 help='Read and print test list FILE, and exit')
Jon Salz0697cbf2012-07-04 15:14:04 +08001315 parser.add_option('--restart', dest='restart',
Jon Salz8fa8e832012-07-13 19:04:09 +08001316 action='store_true',
1317 help='Clear all test state')
Jon Salz0697cbf2012-07-04 15:14:04 +08001318 parser.add_option('--ui', dest='ui', type='choice',
Jon Salz7b5482e2014-08-04 17:48:41 +08001319 choices=['none', 'chrome'],
Jon Salz2f881df2013-02-01 17:00:35 +08001320 default='chrome',
Jon Salz8fa8e832012-07-13 19:04:09 +08001321 help='UI to use')
Jon Salz0697cbf2012-07-04 15:14:04 +08001322 parser.add_option('--ui_scale_factor', dest='ui_scale_factor',
Jon Salz8fa8e832012-07-13 19:04:09 +08001323 type='int', default=1,
1324 help=('Factor by which to scale UI '
1325 '(Chrome UI only)'))
Jon Salz0697cbf2012-07-04 15:14:04 +08001326 parser.add_option('--test_list', dest='test_list',
Jon Salz8fa8e832012-07-13 19:04:09 +08001327 metavar='FILE',
1328 help='Use FILE as test list')
Jon Salzc79a9982012-08-30 04:42:01 +08001329 parser.add_option('--dummy_shopfloor', action='store_true',
1330 help='Use a dummy shopfloor server')
Hung-Te Lincc41d2a2014-10-29 13:35:20 +08001331 parser.add_option('--dummy_connection_manager', action='store_true',
1332 help='Use a dummy connection manager')
Ricky Liang6fe218c2013-12-27 15:17:17 +08001333 parser.add_option('--automation-mode',
1334 choices=[m.lower() for m in AutomationMode],
Ricky Liang45c73e72015-01-15 15:00:30 +08001335 default='none', help='Factory test automation mode.')
Ricky Liang117484a2014-04-14 11:14:41 +08001336 parser.add_option('--no-auto-run-on-start', dest='auto_run_on_start',
1337 action='store_false', default=True,
1338 help=('do not automatically run the test list on goofy '
1339 'start; this is only valid when factory test '
1340 'automation is enabled'))
Chun-Ta Lina8dd3172014-11-26 16:15:13 +08001341 parser.add_option('--handshake_timeout', dest='handshake_timeout',
1342 type='float', default=0.3,
1343 help=('RPC timeout when doing handshake between device '
1344 'and presenter.'))
Vic Yang7d693c42014-09-14 09:52:39 +08001345 parser.add_option('--standalone', dest='standalone',
1346 action='store_true', default=False,
1347 help=('Assume the presenter is running on the same '
1348 'machines.'))
Hung-Te Lin8f6a3782015-01-06 22:58:32 +08001349 parser.add_option('--monolithic', dest='monolithic',
1350 action='store_true', default=False,
1351 help='Run in monolithic mode (without presenter)')
Jon Salz0697cbf2012-07-04 15:14:04 +08001352 (self.options, self.args) = parser.parse_args(args)
1353
Hung-Te Lina846f602014-07-04 20:32:22 +08001354 signal.signal(signal.SIGINT, self.handle_sigint)
1355 # TODO(hungte) SIGTERM does not work properly without Telemetry and should
1356 # be fixed.
Hung-Te Lina846f602014-07-04 20:32:22 +08001357
Jon Salz46b89562012-07-05 11:49:22 +08001358 # Make sure factory directories exist.
1359 factory.get_log_root()
1360 factory.get_state_root()
1361 factory.get_test_data_root()
1362
Jon Salz0697cbf2012-07-04 15:14:04 +08001363 global _inited_logging # pylint: disable=W0603
1364 if not _inited_logging:
1365 factory.init_logging('goofy', verbose=self.options.verbose)
1366 _inited_logging = True
Jon Salz8fa8e832012-07-13 19:04:09 +08001367
Jon Salz0f996602012-10-03 15:26:48 +08001368 if self.options.print_test_list:
Joel Kitchingb85ed7f2014-10-08 18:24:39 +08001369 print(factory.read_test_list(
1370 self.options.print_test_list).__repr__(recursive=True))
Jon Salz0f996602012-10-03 15:26:48 +08001371 sys.exit(0)
1372
Jon Salzee85d522012-07-17 14:34:46 +08001373 event_log.IncrementBootSequence()
Jon Salzd15bbcf2013-05-21 17:33:57 +08001374 # Don't defer logging the initial event, so we can make sure
1375 # that device_id, reimage_id, etc. are all set up.
1376 self.event_log = EventLog('goofy', defer=False)
Jon Salz0697cbf2012-07-04 15:14:04 +08001377
Jon Salz0697cbf2012-07-04 15:14:04 +08001378 if env:
1379 self.env = env
1380 elif factory.in_chroot():
1381 self.env = test_environment.FakeChrootEnvironment()
1382 logging.warn(
Ricky Liang45c73e72015-01-15 15:00:30 +08001383 'Using chroot environment: will not actually run autotests')
Hung-Te Lina846f602014-07-04 20:32:22 +08001384 elif self.options.ui == 'chrome':
Ricky Liang09d66d82014-09-25 11:20:54 +08001385 self.env = test_environment.DUTEnvironment()
Jon Salz0697cbf2012-07-04 15:14:04 +08001386 self.env.goofy = self
Vic Yanga4931152014-08-11 16:36:24 -07001387 # web_socket_manager will be initialized later
1388 # pylint: disable=W0108
1389 self.env.has_sockets = lambda: self.web_socket_manager.has_sockets()
Jon Salz0697cbf2012-07-04 15:14:04 +08001390
1391 if self.options.restart:
1392 state.clear_state()
1393
Jon Salz0697cbf2012-07-04 15:14:04 +08001394 if self.options.ui_scale_factor != 1 and utils.in_qemu():
1395 logging.warn(
Ricky Liang45c73e72015-01-15 15:00:30 +08001396 'In QEMU; ignoring ui_scale_factor argument')
Jon Salz0697cbf2012-07-04 15:14:04 +08001397 self.options.ui_scale_factor = 1
1398
1399 logging.info('Started')
1400
Hung-Te Lin8f6a3782015-01-06 22:58:32 +08001401 if not self.options.monolithic:
Hung-Te Lin7bd55312014-12-30 16:43:36 +08001402 self.link_manager = PresenterLinkManager(
1403 check_interval=1,
1404 handshake_timeout=self.options.handshake_timeout,
1405 standalone=self.options.standalone)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001406
Jon Salz0697cbf2012-07-04 15:14:04 +08001407 self.start_state_server()
1408 self.state_instance.set_shared_data('hwid_cfg', get_hwid_cfg())
1409 self.state_instance.set_shared_data('ui_scale_factor',
Ricky Liang09216dc2013-02-22 17:26:45 +08001410 self.options.ui_scale_factor)
Jon Salz0697cbf2012-07-04 15:14:04 +08001411 self.last_shutdown_time = (
Ricky Liang45c73e72015-01-15 15:00:30 +08001412 self.state_instance.get_shared_data('shutdown_time', optional=True))
Jon Salz0697cbf2012-07-04 15:14:04 +08001413 self.state_instance.del_shared_data('shutdown_time', optional=True)
Jon Salzb19ea072013-02-07 16:35:00 +08001414 self.state_instance.del_shared_data('startup_error', optional=True)
Jon Salz0697cbf2012-07-04 15:14:04 +08001415
Ricky Liang6fe218c2013-12-27 15:17:17 +08001416 self.options.automation_mode = ParseAutomationMode(
1417 self.options.automation_mode)
1418 self.state_instance.set_shared_data('automation_mode',
1419 self.options.automation_mode)
1420 self.state_instance.set_shared_data(
1421 'automation_mode_prompt',
1422 AutomationModePrompt[self.options.automation_mode])
1423
Jon Salz128b0932013-07-03 16:55:26 +08001424 try:
1425 self.InitTestLists()
1426 except: # pylint: disable=W0702
1427 logging.exception('Unable to initialize test lists')
1428 self.state_instance.set_shared_data(
1429 'startup_error',
1430 'Unable to initialize test lists\n%s' % (
1431 traceback.format_exc()))
Jon Salzb19ea072013-02-07 16:35:00 +08001432 if self.options.ui == 'chrome':
1433 # Create an empty test list with default options so that the rest of
1434 # startup can proceed.
1435 self.test_list = factory.FactoryTestList(
1436 [], self.state_instance, factory.Options())
1437 else:
1438 # Bail with an error; no point in starting up.
1439 sys.exit('No valid test list; exiting.')
1440
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001441 self.init_hooks()
1442
Jon Salz822838b2013-03-25 17:32:33 +08001443 if self.test_list.options.clear_state_on_start:
1444 self.state_instance.clear_test_state()
1445
Jon Salz670ce062014-05-16 15:53:50 +08001446 # If the phase is invalid, this will raise a ValueError.
1447 phase.SetPersistentPhase(self.test_list.options.phase)
1448
Dean Liao85ca86f2014-11-03 12:28:08 +08001449 # For netboot firmware, mainfw_type should be 'netboot'.
1450 if (system.SystemInfo().mainfw_type != 'nonchrome' and
1451 system.SystemInfo().firmware_version is None):
Ricky Liang45c73e72015-01-15 15:00:30 +08001452 self.state_instance.set_shared_data(
1453 'startup_error',
Vic Yang9bd4f772013-06-04 17:34:00 +08001454 'Netboot firmware detected\n'
1455 'Connect Ethernet and reboot to re-image.\n'
1456 u'侦测到网路开机固件\n'
1457 u'请连接乙太网并重启')
1458
Jon Salz0697cbf2012-07-04 15:14:04 +08001459 if not self.state_instance.has_shared_data('ui_lang'):
1460 self.state_instance.set_shared_data('ui_lang',
Ricky Liang45c73e72015-01-15 15:00:30 +08001461 self.test_list.options.ui_lang)
Jon Salz0697cbf2012-07-04 15:14:04 +08001462 self.state_instance.set_shared_data(
Ricky Liang45c73e72015-01-15 15:00:30 +08001463 'test_list_options',
1464 self.test_list.options.__dict__)
Jon Salz0697cbf2012-07-04 15:14:04 +08001465 self.state_instance.test_list = self.test_list
1466
Cheng-Yi Chiang39d32ad2013-07-23 15:02:38 +08001467 self.check_log_rotation()
Jon Salz83ef34b2012-11-01 19:46:35 +08001468
Jon Salz23926422012-09-01 03:38:13 +08001469 if self.options.dummy_shopfloor:
Ricky Liang45c73e72015-01-15 15:00:30 +08001470 os.environ[shopfloor.SHOPFLOOR_SERVER_ENV_VAR_NAME] = (
1471 'http://%s:%d/' %
Joel Kitchingb85ed7f2014-10-08 18:24:39 +08001472 (net_utils.LOCALHOST, shopfloor.DEFAULT_SERVER_PORT))
Jon Salz23926422012-09-01 03:38:13 +08001473 self.dummy_shopfloor = Spawn(
1474 [os.path.join(factory.FACTORY_PATH, 'bin', 'shopfloor_server'),
1475 '--dummy'])
1476 elif self.test_list.options.shopfloor_server_url:
1477 shopfloor.set_server_url(self.test_list.options.shopfloor_server_url)
Jon Salz2bf2f6b2013-03-28 18:49:26 +08001478 shopfloor.set_enabled(True)
Jon Salz23926422012-09-01 03:38:13 +08001479
Jon Salz0f996602012-10-03 15:26:48 +08001480 if self.test_list.options.time_sanitizer and not utils.in_chroot():
Jon Salz8fa8e832012-07-13 19:04:09 +08001481 self.time_sanitizer = time_sanitizer.TimeSanitizer(
Ricky Liang45c73e72015-01-15 15:00:30 +08001482 base_time=time_sanitizer.GetBaseTimeFromFile(
1483 # lsb-factory is written by the factory install shim during
1484 # installation, so it should have a good time obtained from
1485 # the mini-Omaha server. If it's not available, we'll use
1486 # /etc/lsb-factory (which will be much older, but reasonably
1487 # sane) and rely on a shopfloor sync to set a more accurate
1488 # time.
1489 '/usr/local/etc/lsb-factory',
1490 '/etc/lsb-release'))
Jon Salz8fa8e832012-07-13 19:04:09 +08001491 self.time_sanitizer.RunOnce()
1492
Vic Yangd8990da2013-06-27 16:57:43 +08001493 if self.test_list.options.check_cpu_usage_period_secs:
Ricky Liang45c73e72015-01-15 15:00:30 +08001494 self.cpu_usage_watcher = Spawn(
1495 ['py/tools/cpu_usage_monitor.py', '-p',
1496 str(self.test_list.options.check_cpu_usage_period_secs)],
Vic Yangd8990da2013-06-27 16:57:43 +08001497 cwd=factory.FACTORY_PATH)
1498
Jon Salz0697cbf2012-07-04 15:14:04 +08001499 self.init_states()
1500 self.start_event_server()
Wei-Ning Huang38b75f02015-02-25 18:25:14 +08001501 self.start_terminal_server()
Hung-Te Lincc41d2a2014-10-29 13:35:20 +08001502
1503 if self.options.dummy_connection_manager:
1504 # Override network manager creation to dummy implmenetation.
1505 logging.info('Using dummy network manager (--dummy_connection_manager).')
1506 self.connection_manager = connection_manager.DummyConnectionManager()
1507 else:
1508 self.connection_manager = self.env.create_connection_manager(
1509 self.test_list.options.wlans,
Mao Huang4340c632015-04-14 14:35:22 +08001510 self.test_list.options.scan_wifi_period_secs,
1511 self.test_list.options.override_blacklisted_network_devices)
Hung-Te Lincc41d2a2014-10-29 13:35:20 +08001512
Jon Salz0697cbf2012-07-04 15:14:04 +08001513 # Note that we create a log watcher even if
1514 # sync_event_log_period_secs isn't set (no background
1515 # syncing), since we may use it to flush event logs as well.
1516 self.log_watcher = EventLogWatcher(
Ricky Liang45c73e72015-01-15 15:00:30 +08001517 self.test_list.options.sync_event_log_period_secs,
1518 event_log_db_file=None,
1519 handle_event_logs_callback=self.handle_event_logs)
Jon Salz0697cbf2012-07-04 15:14:04 +08001520 if self.test_list.options.sync_event_log_period_secs:
1521 self.log_watcher.StartWatchThread()
1522
Cheng-Yi Chianga0f6eff2014-01-09 18:27:22 +08001523 # Creates a system log manager to scan logs periocially.
1524 # A scan includes clearing logs and optionally syncing logs if
1525 # enable_syng_log is True. We kick it to sync logs.
1526 self.system_log_manager = SystemLogManager(
Ricky Liang45c73e72015-01-15 15:00:30 +08001527 sync_log_paths=self.test_list.options.sync_log_paths,
1528 sync_log_period_secs=self.test_list.options.sync_log_period_secs,
1529 scan_log_period_secs=self.test_list.options.scan_log_period_secs,
1530 clear_log_paths=self.test_list.options.clear_log_paths,
1531 clear_log_excluded_paths=self.test_list.options.clear_log_excluded_paths)
Cheng-Yi Chianga0f6eff2014-01-09 18:27:22 +08001532 self.system_log_manager.Start()
Cheng-Yi Chiang344b10f2013-05-03 16:44:03 +08001533
Jon Salz0697cbf2012-07-04 15:14:04 +08001534 self.update_system_info()
1535
Vic Yang4953fc12012-07-26 16:19:53 +08001536 assert ((self.test_list.options.min_charge_pct is None) ==
1537 (self.test_list.options.max_charge_pct is None))
Vic Yange83d9a12013-04-19 20:00:20 +08001538 if utils.in_chroot():
1539 logging.info('In chroot, ignoring charge manager and charge state')
Ricky Liangc392a1c2014-06-20 18:24:59 +08001540 elif (self.test_list.options.enable_charge_manager and
1541 self.test_list.options.min_charge_pct is not None):
Vic Yang4953fc12012-07-26 16:19:53 +08001542 self.charge_manager = ChargeManager(self.test_list.options.min_charge_pct,
1543 self.test_list.options.max_charge_pct)
Jon Salzad7353b2012-10-15 16:22:46 +08001544 system.SystemStatus.charge_manager = self.charge_manager
Cheng-Yi Chiangd8186952013-04-04 23:41:14 +08001545 else:
1546 # Goofy should set charger state to charge if charge_manager is disabled.
Dean Liao88b93192014-10-23 19:37:41 +08001547 self.charge()
Vic Yang4953fc12012-07-26 16:19:53 +08001548
Vic Yang6cee2472014-10-22 17:18:52 -07001549 if CoreDumpManager.CoreDumpEnabled():
1550 self.core_dump_manager = CoreDumpManager(
1551 self.test_list.options.core_dump_watchlist)
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +08001552
Jon Salz0697cbf2012-07-04 15:14:04 +08001553 os.environ['CROS_FACTORY'] = '1'
1554 os.environ['CROS_DISABLE_SITE_SYSINFO'] = '1'
1555
Shuo-Peng Liao1ff502e2013-06-30 18:37:02 +08001556 if not utils.in_chroot() and self.test_list.options.use_cpufreq_manager:
Ricky Liangecddbd42014-07-24 11:32:10 +08001557 logging.info('Enabling CPU frequency manager')
Jon Salzddf0d052013-06-18 12:52:44 +08001558 self.cpufreq_manager = CpufreqManager(event_log=self.event_log)
Jon Salzce6a7f82013-06-10 18:22:54 +08001559
Justin Chuang31b02432013-06-27 15:16:51 +08001560 # Startup hooks may want to skip some tests.
1561 self.update_skipped_tests()
Jon Salz416f9cc2013-05-10 18:32:50 +08001562
Jon Salze12c2b32013-06-25 16:24:34 +08001563 self.find_kcrashes()
1564
Shuo-Peng Liao268b40b2013-07-01 15:58:59 +08001565 # Should not move earlier.
1566 self.hooks.OnStartup()
1567
Ricky Liang36512a32014-07-25 11:47:04 +08001568 # Only after this point the Goofy backend is ready for UI connection.
1569 self.ready_for_ui_connection = True
1570
Ricky Liang650f6bf2012-09-28 13:22:54 +08001571 # Create download path for autotest beforehand or autotests run at
1572 # the same time might fail due to race condition.
1573 if not factory.in_chroot():
1574 utils.TryMakeDirs(os.path.join('/usr/local/autotest', 'tests',
1575 'download'))
1576
Jon Salz0697cbf2012-07-04 15:14:04 +08001577 def state_change_callback(test, test_state):
1578 self.event_client.post_event(
Ricky Liang4bff3e32014-02-20 18:46:11 +08001579 Event(Event.Type.STATE_CHANGE, path=test.path, state=test_state))
Jon Salz0697cbf2012-07-04 15:14:04 +08001580 self.test_list.state_change_callback = state_change_callback
Jon Salz73e0fd02012-04-04 11:46:38 +08001581
Vic Yange2c76a82014-10-30 12:48:19 -07001582 self.autotest_prespawner = prespawner.AutotestPrespawner()
1583 self.autotest_prespawner.start()
1584
1585 self.pytest_prespawner = prespawner.PytestPrespawner()
1586 self.pytest_prespawner.start()
Jon Salza6711d72012-07-18 14:33:03 +08001587
Ricky Liang48e47f92014-02-26 19:31:51 +08001588 tests_after_shutdown = self.state_instance.get_shared_data(
1589 'tests_after_shutdown', optional=True)
Jon Salz57717ca2012-04-04 16:47:25 +08001590
Jon Salz5c344f62012-07-13 14:31:16 +08001591 force_auto_run = (tests_after_shutdown == FORCE_AUTO_RUN)
1592 if not force_auto_run and tests_after_shutdown is not None:
Ricky Liang48e47f92014-02-26 19:31:51 +08001593 logging.info('Resuming tests after shutdown: %s', tests_after_shutdown)
Jon Salz0697cbf2012-07-04 15:14:04 +08001594 self.tests_to_run.extend(
Ricky Liang4bff3e32014-02-20 18:46:11 +08001595 self.test_list.lookup_path(t) for t in tests_after_shutdown)
Peter Ammon1e1ec572014-06-26 17:56:32 -07001596 self.run_enqueue(self.run_next_test)
Jon Salz0697cbf2012-07-04 15:14:04 +08001597 else:
Jon Salz5c344f62012-07-13 14:31:16 +08001598 if force_auto_run or self.test_list.options.auto_run_on_start:
Ricky Liang117484a2014-04-14 11:14:41 +08001599 # If automation mode is enabled, allow suppress auto_run_on_start.
1600 if (self.options.automation_mode == 'NONE' or
1601 self.options.auto_run_on_start):
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +08001602 status_filter = [TestState.UNTESTED]
1603 if self.test_list.options.retry_failed_on_start:
1604 status_filter.append(TestState.FAILED)
1605 self.run_enqueue(lambda: self.run_tests(self.test_list, status_filter))
Jon Salz5c344f62012-07-13 14:31:16 +08001606 self.state_instance.set_shared_data('tests_after_shutdown', None)
Ricky Liang4bff3e32014-02-20 18:46:11 +08001607 self.restore_active_run_state()
Hung-Te Linf2f78f72012-02-08 19:27:11 +08001608
Vic Yang08505c72015-01-06 17:01:53 -08001609 system.GetBoard().OnTestStart()
1610
Dean Liao592e4d52013-01-10 20:06:39 +08001611 self.may_disable_cros_shortcut_keys()
1612
1613 def may_disable_cros_shortcut_keys(self):
1614 test_options = self.test_list.options
1615 if test_options.disable_cros_shortcut_keys:
1616 logging.info('Filter ChromeOS shortcut keys.')
1617 self.key_filter = KeyFilter(
1618 unmap_caps_lock=test_options.disable_caps_lock,
1619 caps_lock_keycode=test_options.caps_lock_keycode)
1620 self.key_filter.Start()
1621
Jon Salz0e6532d2012-10-25 16:30:11 +08001622 def _should_sync_time(self, foreground=False):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001623 """Returns True if we should attempt syncing time with shopfloor.
Jon Salz0e6532d2012-10-25 16:30:11 +08001624
1625 Args:
1626 foreground: If True, synchronizes even if background syncing
1627 is disabled (e.g., in explicit sync requests from the
1628 SyncShopfloor test).
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001629 """
Jon Salz0e6532d2012-10-25 16:30:11 +08001630 return ((foreground or
1631 self.test_list.options.sync_time_period_secs) and
Jon Salz54882d02012-08-31 01:57:54 +08001632 self.time_sanitizer and
1633 (not self.time_synced) and
1634 (not factory.in_chroot()))
1635
Jon Salz0e6532d2012-10-25 16:30:11 +08001636 def sync_time_with_shopfloor_server(self, foreground=False):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001637 """Syncs time with shopfloor server, if not yet synced.
Jon Salz54882d02012-08-31 01:57:54 +08001638
Jon Salz0e6532d2012-10-25 16:30:11 +08001639 Args:
1640 foreground: If True, synchronizes even if background syncing
1641 is disabled (e.g., in explicit sync requests from the
1642 SyncShopfloor test).
1643
Jon Salz54882d02012-08-31 01:57:54 +08001644 Returns:
1645 False if no time sanitizer is available, or True if this sync (or a
1646 previous sync) succeeded.
1647
1648 Raises:
1649 Exception if unable to contact the shopfloor server.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001650 """
Jon Salz0e6532d2012-10-25 16:30:11 +08001651 if self._should_sync_time(foreground):
Jon Salz54882d02012-08-31 01:57:54 +08001652 self.time_sanitizer.SyncWithShopfloor()
1653 self.time_synced = True
1654 return self.time_synced
1655
Jon Salzb92c5112012-09-21 15:40:11 +08001656 def log_disk_space_stats(self):
Jon Salz18e0e022013-06-11 17:13:39 +08001657 if (utils.in_chroot() or
1658 not self.test_list.options.log_disk_space_period_secs):
Jon Salzb92c5112012-09-21 15:40:11 +08001659 return
1660
1661 now = time.time()
1662 if (self.last_log_disk_space_time and
1663 now - self.last_log_disk_space_time <
1664 self.test_list.options.log_disk_space_period_secs):
1665 return
1666 self.last_log_disk_space_time = now
1667
Cheng-Yi Chiangd0406522013-04-01 15:40:18 +08001668 # Upload event if stateful partition usage is above threshold.
1669 # Stateful partition is mounted on /usr/local, while
1670 # encrypted stateful partition is mounted on /var.
1671 # If there are too much logs in the factory process,
1672 # these two partitions might get full.
Jon Salzb92c5112012-09-21 15:40:11 +08001673 try:
Cheng-Yi Chiangd0406522013-04-01 15:40:18 +08001674 vfs_infos = disk_space.GetAllVFSInfo()
1675 stateful_info, encrypted_info = None, None
1676 for vfs_info in vfs_infos.values():
1677 if '/usr/local' in vfs_info.mount_points:
1678 stateful_info = vfs_info
1679 if '/var' in vfs_info.mount_points:
1680 encrypted_info = vfs_info
1681
1682 stateful = disk_space.GetPartitionUsage(stateful_info)
1683 encrypted = disk_space.GetPartitionUsage(encrypted_info)
1684
Ricky Liang45c73e72015-01-15 15:00:30 +08001685 above_threshold = (
Cheng-Yi Chiangd0406522013-04-01 15:40:18 +08001686 self.test_list.options.stateful_usage_threshold and
1687 max(stateful.bytes_used_pct,
1688 stateful.inodes_used_pct,
1689 encrypted.bytes_used_pct,
1690 encrypted.inodes_used_pct) >
Ricky Liang45c73e72015-01-15 15:00:30 +08001691 self.test_list.options.stateful_usage_threshold)
Cheng-Yi Chiangd0406522013-04-01 15:40:18 +08001692
1693 if above_threshold:
1694 self.event_log.Log('stateful_partition_usage',
Ricky Liang45c73e72015-01-15 15:00:30 +08001695 partitions={
1696 'stateful': {
1697 'bytes_used_pct': FloatDigit(stateful.bytes_used_pct, 2),
1698 'inodes_used_pct': FloatDigit(stateful.inodes_used_pct, 2)},
1699 'encrypted_stateful': {
1700 'bytes_used_pct': FloatDigit(encrypted.bytes_used_pct, 2),
1701 'inodes_used_pct': FloatDigit(encrypted.inodes_used_pct, 2)}
1702 })
Cheng-Yi Chiang1b722322015-03-16 20:07:03 +08001703 self.log_watcher.KickWatchThread()
Cheng-Yi Chiang00798e72013-06-20 18:16:39 +08001704 if (not utils.in_chroot() and
1705 self.test_list.options.stateful_usage_above_threshold_action):
1706 Spawn(self.test_list.options.stateful_usage_above_threshold_action,
1707 call=True)
Cheng-Yi Chiangd0406522013-04-01 15:40:18 +08001708
1709 message = disk_space.FormatSpaceUsedAll(vfs_infos)
Jon Salz3c493bb2013-02-07 17:24:58 +08001710 if message != self.last_log_disk_space_message:
Cheng-Yi Chiangd0406522013-04-01 15:40:18 +08001711 if above_threshold:
1712 logging.warning(message)
1713 else:
1714 logging.info(message)
Jon Salz3c493bb2013-02-07 17:24:58 +08001715 self.last_log_disk_space_message = message
Jon Salzb92c5112012-09-21 15:40:11 +08001716 except: # pylint: disable=W0702
1717 logging.exception('Unable to get disk space used')
1718
Justin Chuang83813982013-05-13 01:26:32 +08001719 def check_battery(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001720 """Checks the current battery status.
Justin Chuang83813982013-05-13 01:26:32 +08001721
1722 Logs current battery charging level and status to log. If the battery level
1723 is lower below warning_low_battery_pct, send warning event to shopfloor.
1724 If the battery level is lower below critical_low_battery_pct, flush disks.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001725 """
Justin Chuang83813982013-05-13 01:26:32 +08001726 if not self.test_list.options.check_battery_period_secs:
1727 return
1728
1729 now = time.time()
1730 if (self.last_check_battery_time and
1731 now - self.last_check_battery_time <
1732 self.test_list.options.check_battery_period_secs):
1733 return
1734 self.last_check_battery_time = now
1735
1736 message = ''
1737 log_level = logging.INFO
1738 try:
1739 power = system.GetBoard().power
1740 if not power.CheckBatteryPresent():
1741 message = 'Battery is not present'
1742 else:
1743 ac_present = power.CheckACPresent()
1744 charge_pct = power.GetChargePct(get_float=True)
1745 message = ('Current battery level %.1f%%, AC charger is %s' %
1746 (charge_pct, 'connected' if ac_present else 'disconnected'))
1747
1748 if charge_pct > self.test_list.options.critical_low_battery_pct:
1749 critical_low_battery = False
1750 else:
1751 critical_low_battery = True
1752 # Only sync disks when battery level is still above minimum
1753 # value. This can be used for offline analysis when shopfloor cannot
1754 # be connected.
1755 if charge_pct > MIN_BATTERY_LEVEL_FOR_DISK_SYNC:
1756 logging.warning('disk syncing for critical low battery situation')
1757 os.system('sync; sync; sync')
1758 else:
1759 logging.warning('disk syncing is cancelled '
1760 'because battery level is lower than %.1f',
1761 MIN_BATTERY_LEVEL_FOR_DISK_SYNC)
1762
1763 # Notify shopfloor server
1764 if (critical_low_battery or
1765 (not ac_present and
1766 charge_pct <= self.test_list.options.warning_low_battery_pct)):
1767 log_level = logging.WARNING
1768
1769 self.event_log.Log('low_battery',
1770 battery_level=charge_pct,
1771 charger_connected=ac_present,
1772 critical=critical_low_battery)
1773 self.log_watcher.KickWatchThread()
Cheng-Yi Chianga0f6eff2014-01-09 18:27:22 +08001774 if self.test_list.options.enable_sync_log:
1775 self.system_log_manager.KickToSync()
Ricky Liang45c73e72015-01-15 15:00:30 +08001776 except: # pylint: disable=W0702
Justin Chuang83813982013-05-13 01:26:32 +08001777 logging.exception('Unable to check battery or notify shopfloor')
1778 finally:
1779 if message != self.last_check_battery_message:
1780 logging.log(log_level, message)
1781 self.last_check_battery_message = message
1782
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +08001783 def check_core_dump(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001784 """Checks if there is any core dumped file.
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +08001785
1786 Removes unwanted core dump files immediately.
1787 Syncs those files matching watch list to server with a delay between
1788 each sync. After the files have been synced to server, deletes the files.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001789 """
Vic Yang6cee2472014-10-22 17:18:52 -07001790 if not self.core_dump_manager:
1791 return
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +08001792 core_dump_files = self.core_dump_manager.ScanFiles()
1793 if core_dump_files:
1794 now = time.time()
1795 if (self.last_kick_sync_time and now - self.last_kick_sync_time <
1796 self.test_list.options.kick_sync_min_interval_secs):
1797 return
1798 self.last_kick_sync_time = now
1799
1800 # Sends event to server
1801 self.event_log.Log('core_dumped', files=core_dump_files)
1802 self.log_watcher.KickWatchThread()
1803
1804 # Syncs files to server
Cheng-Yi Chianga0f6eff2014-01-09 18:27:22 +08001805 if self.test_list.options.enable_sync_log:
1806 self.system_log_manager.KickToSync(
Cheng-Yi Chiangd3516a32013-07-17 15:30:47 +08001807 core_dump_files, self.core_dump_manager.ClearFiles)
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +08001808
Cheng-Yi Chiang39d32ad2013-07-23 15:02:38 +08001809 def check_log_rotation(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001810 """Checks log rotation file presence/absence according to test_list option.
Cheng-Yi Chiang39d32ad2013-07-23 15:02:38 +08001811
1812 Touch /var/lib/cleanup_logs_paused if test_list.options.disable_log_rotation
1813 is True, delete it otherwise. This must be done in idle loop because
1814 autotest client will touch /var/lib/cleanup_logs_paused each time it runs
1815 an autotest.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001816 """
Cheng-Yi Chiang39d32ad2013-07-23 15:02:38 +08001817 if utils.in_chroot():
1818 return
1819 try:
1820 if self.test_list.options.disable_log_rotation:
1821 open(CLEANUP_LOGS_PAUSED, 'w').close()
1822 else:
1823 file_utils.TryUnlink(CLEANUP_LOGS_PAUSED)
1824 except: # pylint: disable=W0702
1825 # Oh well. Logs an error (but no trace)
1826 logging.info(
1827 'Unable to %s %s: %s',
1828 'touch' if self.test_list.options.disable_log_rotation else 'delete',
1829 CLEANUP_LOGS_PAUSED, utils.FormatExceptionOnly())
1830
Jon Salz8fa8e832012-07-13 19:04:09 +08001831 def sync_time_in_background(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001832 """Writes out current time and tries to sync with shopfloor server."""
Jon Salzb22d1172012-08-06 10:38:57 +08001833 if not self.time_sanitizer:
1834 return
1835
1836 # Write out the current time.
1837 self.time_sanitizer.SaveTime()
1838
Jon Salz54882d02012-08-31 01:57:54 +08001839 if not self._should_sync_time():
Jon Salz8fa8e832012-07-13 19:04:09 +08001840 return
1841
1842 now = time.time()
1843 if self.last_sync_time and (
1844 now - self.last_sync_time <
1845 self.test_list.options.sync_time_period_secs):
1846 # Not yet time for another check.
1847 return
1848 self.last_sync_time = now
1849
1850 def target():
1851 try:
Jon Salz54882d02012-08-31 01:57:54 +08001852 self.sync_time_with_shopfloor_server()
Jon Salz8fa8e832012-07-13 19:04:09 +08001853 except: # pylint: disable=W0702
1854 # Oh well. Log an error (but no trace)
1855 logging.info(
Ricky Liang45c73e72015-01-15 15:00:30 +08001856 'Unable to get time from shopfloor server: %s',
1857 utils.FormatExceptionOnly())
Jon Salz8fa8e832012-07-13 19:04:09 +08001858
1859 thread = threading.Thread(target=target)
1860 thread.daemon = True
1861 thread.start()
1862
Peter Ammon1e1ec572014-06-26 17:56:32 -07001863 def perform_periodic_tasks(self):
1864 """Override of base method to perform periodic work.
Vic Yang4953fc12012-07-26 16:19:53 +08001865
Peter Ammon1e1ec572014-06-26 17:56:32 -07001866 This method must not raise exceptions.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001867 """
Peter Ammon1e1ec572014-06-26 17:56:32 -07001868 super(Goofy, self).perform_periodic_tasks()
Jon Salzb22d1172012-08-06 10:38:57 +08001869
Vic Yang311ddb82012-09-26 12:08:28 +08001870 self.check_exclusive()
cychiang21886742012-07-05 15:16:32 +08001871 self.check_for_updates()
Jon Salz8fa8e832012-07-13 19:04:09 +08001872 self.sync_time_in_background()
Jon Salzb92c5112012-09-21 15:40:11 +08001873 self.log_disk_space_stats()
Justin Chuang83813982013-05-13 01:26:32 +08001874 self.check_battery()
Cheng-Yi Chiangcdfa4182013-05-05 03:20:19 +08001875 self.check_core_dump()
Cheng-Yi Chiang39d32ad2013-07-23 15:02:38 +08001876 self.check_log_rotation()
Jon Salz57717ca2012-04-04 16:47:25 +08001877
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001878 def handle_event_logs(self, chunks, periodic=False):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001879 """Callback for event watcher.
Jon Salz258a40c2012-04-19 12:34:01 +08001880
Jon Salz0697cbf2012-07-04 15:14:04 +08001881 Attempts to upload the event logs to the shopfloor server.
Vic Yang93027612013-05-06 02:42:49 +08001882
1883 Args:
Jon Salzd15bbcf2013-05-21 17:33:57 +08001884 chunks: A list of Chunk objects.
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001885 periodic: This event log handling is periodic. Error messages
1886 will only be shown for the first time.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001887 """
Vic Yang93027612013-05-06 02:42:49 +08001888 first_exception = None
1889 exception_count = 0
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001890 # Suppress error messages for periodic event syncing except for the
1891 # first time. If event syncing is not periodic, always show the error
1892 # messages.
1893 quiet = self._suppress_event_log_error_messages if periodic else False
Vic Yang93027612013-05-06 02:42:49 +08001894
Jon Salzd15bbcf2013-05-21 17:33:57 +08001895 for chunk in chunks:
Vic Yang93027612013-05-06 02:42:49 +08001896 try:
Jon Salzcddb6402013-05-23 12:56:42 +08001897 description = 'event logs (%s)' % str(chunk)
Vic Yang93027612013-05-06 02:42:49 +08001898 start_time = time.time()
1899 shopfloor_client = shopfloor.get_instance(
Ricky Liang45c73e72015-01-15 15:00:30 +08001900 detect=True,
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001901 timeout=self.test_list.options.shopfloor_timeout_secs,
1902 quiet=quiet)
Ricky Liang45c73e72015-01-15 15:00:30 +08001903 shopfloor_client.UploadEvent(chunk.log_name + '.' +
Jon Salzd15bbcf2013-05-21 17:33:57 +08001904 event_log.GetReimageId(),
1905 Binary(chunk.chunk))
Vic Yang93027612013-05-06 02:42:49 +08001906 logging.info(
Ricky Liang45c73e72015-01-15 15:00:30 +08001907 'Successfully synced %s in %.03f s',
1908 description, time.time() - start_time)
1909 except: # pylint: disable=W0702
Jon Salzd15bbcf2013-05-21 17:33:57 +08001910 first_exception = (first_exception or (chunk.log_name + ': ' +
Vic Yang93027612013-05-06 02:42:49 +08001911 utils.FormatExceptionOnly()))
1912 exception_count += 1
1913
1914 if exception_count:
1915 if exception_count == 1:
1916 msg = 'Log upload failed: %s' % first_exception
1917 else:
1918 msg = '%d log upload failed; first is: %s' % (
1919 exception_count, first_exception)
Cheng-Yi Chiangf5b21012015-03-17 15:37:14 +08001920 # For periodic event log syncing, only show the first error messages.
1921 if periodic:
1922 if not self._suppress_event_log_error_messages:
1923 self._suppress_event_log_error_messages = True
1924 logging.warning('Suppress periodic shopfloor error messages for '
1925 'event log syncing after the first one.')
1926 raise Exception(msg)
1927 # For event log syncing by request, show the error messages.
1928 else:
1929 raise Exception(msg)
Vic Yang93027612013-05-06 02:42:49 +08001930
Ricky Liang45c73e72015-01-15 15:00:30 +08001931 def run_tests_with_status(self, statuses_to_run, starting_at=None, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001932 """Runs all top-level tests with a particular status.
Jon Salz0405ab52012-03-16 15:26:52 +08001933
Jon Salz0697cbf2012-07-04 15:14:04 +08001934 All active tests, plus any tests to re-run, are reset.
Jon Salz57717ca2012-04-04 16:47:25 +08001935
Jon Salz0697cbf2012-07-04 15:14:04 +08001936 Args:
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001937 statuses_to_run: The particular status that caller wants to run.
Jon Salz0697cbf2012-07-04 15:14:04 +08001938 starting_at: If provided, only auto-runs tests beginning with
1939 this test.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001940 root: The root of tests to run. If not provided, it will be
1941 the root of all tests.
1942 """
Jon Salz0697cbf2012-07-04 15:14:04 +08001943 root = root or self.test_list
Jon Salz57717ca2012-04-04 16:47:25 +08001944
Jon Salz0697cbf2012-07-04 15:14:04 +08001945 if starting_at:
1946 # Make sure they passed a test, not a string.
1947 assert isinstance(starting_at, factory.FactoryTest)
Jon Salz0405ab52012-03-16 15:26:52 +08001948
Jon Salz0697cbf2012-07-04 15:14:04 +08001949 tests_to_reset = []
1950 tests_to_run = []
Jon Salz0405ab52012-03-16 15:26:52 +08001951
Jon Salz0697cbf2012-07-04 15:14:04 +08001952 found_starting_at = False
Jon Salz0405ab52012-03-16 15:26:52 +08001953
Jon Salz0697cbf2012-07-04 15:14:04 +08001954 for test in root.get_top_level_tests():
1955 if starting_at:
1956 if test == starting_at:
1957 # We've found starting_at; do auto-run on all
1958 # subsequent tests.
1959 found_starting_at = True
1960 if not found_starting_at:
1961 # Don't start this guy yet
1962 continue
Jon Salz0405ab52012-03-16 15:26:52 +08001963
Jon Salz0697cbf2012-07-04 15:14:04 +08001964 status = test.get_state().status
1965 if status == TestState.ACTIVE or status in statuses_to_run:
1966 # Reset the test (later; we will need to abort
1967 # all active tests first).
1968 tests_to_reset.append(test)
1969 if status in statuses_to_run:
1970 tests_to_run.append(test)
Jon Salz0405ab52012-03-16 15:26:52 +08001971
Jon Salz6dc031d2013-06-19 13:06:23 +08001972 self.abort_active_tests('Operator requested run/re-run of certain tests')
Jon Salz258a40c2012-04-19 12:34:01 +08001973
Jon Salz0697cbf2012-07-04 15:14:04 +08001974 # Reset all statuses of the tests to run (in case any tests were active;
1975 # we want them to be run again).
1976 for test_to_reset in tests_to_reset:
1977 for test in test_to_reset.walk():
1978 test.update_state(status=TestState.UNTESTED)
Jon Salz57717ca2012-04-04 16:47:25 +08001979
Chih-Yu Huang85dc63c2015-08-12 15:21:28 +08001980 self.run_tests(tests_to_run, [TestState.UNTESTED])
Jon Salz0405ab52012-03-16 15:26:52 +08001981
Jon Salz0697cbf2012-07-04 15:14:04 +08001982 def restart_tests(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001983 """Restarts all tests."""
Jon Salz0697cbf2012-07-04 15:14:04 +08001984 root = root or self.test_list
Jon Salz0405ab52012-03-16 15:26:52 +08001985
Jon Salz6dc031d2013-06-19 13:06:23 +08001986 self.abort_active_tests('Operator requested restart of certain tests')
Jon Salz0697cbf2012-07-04 15:14:04 +08001987 for test in root.walk():
Ricky Liangfea4ac92014-08-21 11:55:59 +08001988 test.update_state(status=TestState.UNTESTED)
Jon Salz0697cbf2012-07-04 15:14:04 +08001989 self.run_tests(root)
Hung-Te Lin96632362012-03-20 21:14:18 +08001990
Jon Salz0697cbf2012-07-04 15:14:04 +08001991 def auto_run(self, starting_at=None, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001992 """"Auto-runs" tests that have not been run yet.
Hung-Te Lin96632362012-03-20 21:14:18 +08001993
Jon Salz0697cbf2012-07-04 15:14:04 +08001994 Args:
1995 starting_at: If provide, only auto-runs tests beginning with
1996 this test.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08001997 root: If provided, the root of tests to run. If not provided, the root
1998 will be test_list (root of all tests).
1999 """
Jon Salz0697cbf2012-07-04 15:14:04 +08002000 root = root or self.test_list
2001 self.run_tests_with_status([TestState.UNTESTED, TestState.ACTIVE],
Ricky Liang45c73e72015-01-15 15:00:30 +08002002 starting_at=starting_at,
2003 root=root)
Jon Salz968e90b2012-03-18 16:12:43 +08002004
Jon Salz0697cbf2012-07-04 15:14:04 +08002005 def re_run_failed(self, root=None):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08002006 """Re-runs failed tests."""
Jon Salz0697cbf2012-07-04 15:14:04 +08002007 root = root or self.test_list
2008 self.run_tests_with_status([TestState.FAILED], root=root)
Jon Salz57717ca2012-04-04 16:47:25 +08002009
Jon Salz0697cbf2012-07-04 15:14:04 +08002010 def show_review_information(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08002011 """Event handler for showing review information screen.
Jon Salz57717ca2012-04-04 16:47:25 +08002012
Peter Ammon1e1ec572014-06-26 17:56:32 -07002013 The information screen is rendered by main UI program (ui.py), so in
Jon Salz0697cbf2012-07-04 15:14:04 +08002014 goofy we only need to kill all active tests, set them as untested, and
2015 clear remaining tests.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08002016 """
Jon Salz0697cbf2012-07-04 15:14:04 +08002017 self.kill_active_tests(False)
Jon Salza6711d72012-07-18 14:33:03 +08002018 self.cancel_pending_tests()
Jon Salz57717ca2012-04-04 16:47:25 +08002019
Jon Salz0697cbf2012-07-04 15:14:04 +08002020 def handle_switch_test(self, event):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08002021 """Switches to a particular test.
Jon Salz0405ab52012-03-16 15:26:52 +08002022
Ricky Liang6fe218c2013-12-27 15:17:17 +08002023 Args:
2024 event: The SWITCH_TEST event.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08002025 """
Jon Salz0697cbf2012-07-04 15:14:04 +08002026 test = self.test_list.lookup_path(event.path)
2027 if not test:
2028 logging.error('Unknown test %r', event.key)
2029 return
Jon Salz73e0fd02012-04-04 11:46:38 +08002030
Jon Salz0697cbf2012-07-04 15:14:04 +08002031 invoc = self.invocations.get(test)
2032 if invoc and test.backgroundable:
2033 # Already running: just bring to the front if it
2034 # has a UI.
2035 logging.info('Setting visible test to %s', test.path)
Jon Salz36fbbb52012-07-05 13:45:06 +08002036 self.set_visible_test(test)
Jon Salz0697cbf2012-07-04 15:14:04 +08002037 return
Jon Salz73e0fd02012-04-04 11:46:38 +08002038
Jon Salz6dc031d2013-06-19 13:06:23 +08002039 self.abort_active_tests('Operator requested abort (switch_test)')
Jon Salz0697cbf2012-07-04 15:14:04 +08002040 for t in test.walk():
2041 t.update_state(status=TestState.UNTESTED)
Jon Salz73e0fd02012-04-04 11:46:38 +08002042
Jon Salz0697cbf2012-07-04 15:14:04 +08002043 if self.test_list.options.auto_run_on_keypress:
2044 self.auto_run(starting_at=test)
2045 else:
2046 self.run_tests(test)
Jon Salz73e0fd02012-04-04 11:46:38 +08002047
Wei-Ning Huang38b75f02015-02-25 18:25:14 +08002048 def handle_key_filter_mode(self, event):
2049 if self.key_filter:
2050 if getattr(event, 'enabled'):
2051 self.key_filter.Start()
2052 else:
2053 self.key_filter.Stop()
2054
Jon Salz0697cbf2012-07-04 15:14:04 +08002055 def wait(self):
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08002056 """Waits for all pending invocations.
Jon Salz0697cbf2012-07-04 15:14:04 +08002057
2058 Useful for testing.
Cheng-Yi Chiang1e3e2692013-12-24 18:02:36 +08002059 """
Jon Salz1acc8742012-07-17 17:45:55 +08002060 while self.invocations:
2061 for k, v in self.invocations.iteritems():
2062 logging.info('Waiting for %s to complete...', k)
2063 v.thread.join()
2064 self.reap_completed_tests()
Jon Salz0697cbf2012-07-04 15:14:04 +08002065
Claire Changd1961a22015-08-05 16:15:55 +08002066 def test_fail(self, test):
2067 system.GetBoard().OnTestFailure(test)
2068 if self.link_manager:
2069 self.link_manager.UpdateStatus(False)
2070
Hung-Te Linf2f78f72012-02-08 19:27:11 +08002071if __name__ == '__main__':
Peter Ammona3d298c2014-09-23 10:11:02 -07002072 Goofy.run_main_and_exit()