1 # Copyright (c) 2012 The Chromium OS Authors. All rights reserved. 2 # Use of this source code is governed by a BSD-style license that can be 3 # found in the LICENSE file. 4 5 import collections, logging, os, re, shutil, time 6 7 from autotest_lib.client.bin import utils 8 from autotest_lib.client.common_lib import error 9 from autotest_lib.client.cros import cros_logging 10 from autotest_lib.client.cros.power import power_status 11 from autotest_lib.client.cros.power import power_utils 12 from autotest_lib.client.cros.power import sys_power 13 #pylint: disable=W0611 14 from autotest_lib.client.cros import flimflam_test_path 15 import flimflam 16 17 class Suspender(object): 18 """Class for suspend/resume measurements. 19 20 Public attributes: 21 disconnect_3G_time: Amount of seconds it took to disable 3G. 22 successes[]: List of timing measurement dicts from successful suspends. 23 failures[]: List of SuspendFailure exceptions from failed suspends. 24 device_times[]: List of individual device suspend/resume time dicts. 25 26 Public methods: 27 suspend: Do a suspend/resume cycle. Return timing measurement dict. 28 29 Private attributes: 30 _logs: Array of /var/log/messages lines since start of suspend cycle. 31 _log_file: Open file descriptor at the end of /var/log/messages. 32 _logdir: Directory to store firmware logs in case of errors. 33 _suspend: Set to the sys_power suspend function to use. 34 _throw: Set to have SuspendFailure exceptions raised to the caller. 35 _reset_pm_print_times: Set to deactivate pm_print_times after the test. 36 _restart_tlsdated: Set to restart tlsdated after the test. 37 38 Private methods: 39 __init__: Shuts off tlsdated for duration of test, disables 3G 40 __del__: Restore tlsdated (must run eventually, but GC delay no problem) 41 _set_pm_print_times: Enable/disable kernel device suspend timing output. 42 _check_failure_log: Check /sys/.../suspend_stats for new failures. 43 _ts: Returns a timestamp from /run/power_manager/last_resume_timings 44 _hwclock_ts: Read RTC timestamp left on resume in hwclock-on-resume 45 _device_resume_time: Read seconds overall device resume took from logs. 46 _individual_device_times: Reads individual device suspend/resume times. 47 _identify_driver: Return the driver name of a device (or "unknown"). 48 """ 49 50 # board-specific "time to suspend" values determined empirically 51 # TODO: migrate to separate file with http://crosbug.com/38148 52 _DEFAULT_SUSPEND_DELAY = 5 53 _SUSPEND_DELAY = { 54 # TODO: Reevaluate this when http://crosbug.com/38460 is fixed 55 'daisy': 6, 56 'daisy_spring': 6, 57 'peach_pit': 6, 58 59 # TODO: Reevaluate these when http://crosbug.com/38225 is fixed 60 'x86-mario': 6, 61 'x86-alex': 5, 62 63 # Lumpy and Stumpy need high values, because it seems to mitigate their 64 # RTC interrupt problem. See http://crosbug.com/36004 65 'lumpy': 5, 66 'stumpy': 5, 67 68 # RTS5209 card reader has a really bad staging driver, can take ~1 sec 69 'butterfly': 4, 70 71 # Hard disk sync and overall just slow 72 'parrot': 8, 73 'kiev': 9, 74 } 75 76 # alarm/not_before value guaranteed to raise SpuriousWakeup in _hwclock_ts 77 _ALARM_FORCE_EARLY_WAKEUP = 2147483647 78 79 # File written by send_metrics_on_resume containing timing information about 80 # the last resume. 81 _TIMINGS_FILE = '/run/power_manager/root/last_resume_timings' 82 83 # Amount of lines to dump from the eventlog on a SpuriousWakeup. Should be 84 # enough to include ACPI Wake Reason... 10 should be far on the safe side. 85 _RELEVANT_EVENTLOG_LINES = 10 86 87 # Sanity check value to catch overlong resume times (from missed RTC wakes) 88 _MAX_RESUME_TIME = 10 89 90 # File written by powerd_suspend containing the hwclock time at resume. 91 HWCLOCK_FILE = '/run/power_manager/root/hwclock-on-resume' 92 93 # File read by powerd to decide on the state to suspend (mem or freeze). 94 _SUSPEND_STATE_PREF_FILE = 'suspend_to_idle' 95 96 def __init__(self, logdir, method=sys_power.do_suspend, 97 throw=False, device_times=False, suspend_state=''): 98 """ 99 Prepare environment for suspending. 100 @param suspend_state: Suspend state to enter into. It can be 101 'mem' or 'freeze' or an empty string. If 102 the suspend state is an empty string, 103 system suspends to the default pref. 104 """ 105 self.disconnect_3G_time = 0 106 self.successes = [] 107 self.failures = [] 108 self._logdir = logdir 109 self._suspend = method 110 self._throw = throw 111 self._reset_pm_print_times = False 112 self._restart_tlsdated = False 113 self._log_file = None 114 self._suspend_state = suspend_state 115 if device_times: 116 self.device_times = [] 117 118 # stop tlsdated, make sure we/hwclock have /dev/rtc for ourselves 119 if utils.system_output('initctl status tlsdated').find('start') != -1: 120 utils.system('initctl stop tlsdated') 121 self._restart_tlsdated = True 122 # give process's file descriptors time to asynchronously tear down 123 time.sleep(0.1) 124 125 # prime powerd_suspend RTC timestamp saving and make sure hwclock works 126 utils.open_write_close(self.HWCLOCK_FILE, '') 127 hwclock_output = utils.system_output('hwclock -r --debug --utc', 128 ignore_status=True) 129 if not re.search('Using.*/dev interface to.*clock', hwclock_output): 130 raise error.TestError('hwclock cannot find rtc: ' + hwclock_output) 131 132 # activate device suspend timing debug output 133 if hasattr(self, 'device_times'): 134 if not int(utils.read_one_line('/sys/power/pm_print_times')): 135 self._set_pm_print_times(True) 136 self._reset_pm_print_times = True 137 138 # Shut down 3G to remove its variability from suspend time measurements 139 flim = flimflam.FlimFlam() 140 service = flim.FindCellularService(0) 141 if service: 142 logging.info('Found 3G interface, disconnecting.') 143 start_time = time.time() 144 (success, status) = flim.DisconnectService( 145 service=service, wait_timeout=60) 146 if success: 147 logging.info('3G disconnected successfully.') 148 self.disconnect_3G_time = time.time() - start_time 149 else: 150 logging.error('Could not disconnect: %s.', status) 151 self.disconnect_3G_time = -1 152 153 self._configure_suspend_state() 154 155 156 def _configure_suspend_state(self): 157 """Configure the suspend state as requested.""" 158 if self._suspend_state: 159 available_suspend_states = utils.read_one_line('/sys/power/state') 160 if self._suspend_state not in available_suspend_states: 161 raise error.TestNAError('Invalid suspend state: ' + 162 self._suspend_state) 163 # Check the current state. If it is same as the one requested, 164 # we don't want to call PowerPrefChanger(restarts powerd). 165 if self._suspend_state == power_utils.get_sleep_state(): 166 return 167 should_freeze = '1' if self._suspend_state == 'freeze' else '0' 168 new_prefs = {self._SUSPEND_STATE_PREF_FILE: should_freeze} 169 self._power_pref_changer = power_utils.PowerPrefChanger(new_prefs) 170 171 172 def _set_pm_print_times(self, on): 173 """Enable/disable extra suspend timing output from powerd to syslog.""" 174 if utils.system('echo %s > /sys/power/pm_print_times' % int(bool(on)), 175 ignore_status=True): 176 logging.warning('Failed to set pm_print_times to %s', bool(on)) 177 del self.device_times 178 self._reset_pm_print_times = False 179 else: 180 logging.info('Device resume times set to %s', bool(on)) 181 182 183 def _get_board(self): 184 """Remove _freon from get_board if found.""" 185 return (utils.get_board().replace("_freon", "")) 186 187 188 def _reset_logs(self): 189 """Throw away cached log lines and reset log pointer to current end.""" 190 if self._log_file: 191 self._log_file.close() 192 self._log_file = open('/var/log/messages') 193 self._log_file.seek(0, os.SEEK_END) 194 self._logs = [] 195 196 197 def _update_logs(self, retries=11): 198 """ 199 Read all lines logged since last reset into log cache. Block until last 200 powerd_suspend resume message was read, raise if it takes too long. 201 """ 202 finished_regex = re.compile(r'powerd_suspend\[\d+\]: Resume finished') 203 for retry in xrange(retries + 1): 204 lines = self._log_file.readlines() 205 if lines: 206 if self._logs and self._logs[-1][-1] != '\n': 207 # Reassemble line that was cut in the middle 208 self._logs[-1] += lines.pop(0) 209 self._logs += lines 210 for line in reversed(self._logs): 211 if (finished_regex.search(line)): 212 return 213 time.sleep(0.005 * 2**retry) 214 215 raise error.TestError("Sanity check failed: did not try to suspend.") 216 217 218 def _ts(self, name, retries=11): 219 """Searches logs for last timestamp with a given suspend message.""" 220 # Occasionally need to retry due to races from process wakeup order 221 for retry in xrange(retries + 1): 222 try: 223 f = open(self._TIMINGS_FILE) 224 for line in f: 225 words = line.split('=') 226 if name == words[0]: 227 try: 228 timestamp = float(words[1]) 229 except ValueError: 230 logging.warning('Invalid timestamp: %s', line) 231 timestamp = 0 232 return timestamp 233 except IOError: 234 pass 235 time.sleep(0.005 * 2**retry) 236 237 raise error.TestError('Could not find %s entry.' % name) 238 239 240 def _hwclock_ts(self, not_before): 241 """Read the RTC resume timestamp saved by powerd_suspend.""" 242 early_wakeup = False 243 if os.path.exists(self.HWCLOCK_FILE): 244 # TODO(crbug.com/733773): Still fragile see bug. 245 match = re.search(r'(.+)(\.\d+)[+-]\d+:?\d+$', 246 utils.read_file(self.HWCLOCK_FILE), re.DOTALL) 247 if match: 248 timeval = time.strptime(match.group(1), "%Y-%m-%d %H:%M:%S") 249 seconds = time.mktime(timeval) 250 seconds += float(match.group(2)) 251 logging.debug('RTC resume timestamp read: %f', seconds) 252 if seconds >= not_before: 253 return seconds 254 early_wakeup = True 255 if early_wakeup: 256 logging.debug('Early wakeup, dumping eventlog if it exists:\n') 257 elog = utils.system_output('mosys eventlog list | tail -n %d' % 258 self._RELEVANT_EVENTLOG_LINES, ignore_status=True) 259 wake_elog = (['unknown'] + re.findall(r'Wake Source.*', elog))[-1] 260 for line in reversed(self._logs): 261 match = re.search(r'PM1_STS: WAK.*', line) 262 if match: 263 wake_syslog = match.group(0) 264 break 265 else: 266 wake_syslog = 'unknown' 267 for b, e, s in sys_power.SpuriousWakeupError.S3_WHITELIST: 268 if (re.search(b, utils.get_board()) and 269 re.search(e, wake_elog) and re.search(s, wake_syslog)): 270 logging.warning('Whitelisted spurious wake in S3: %s | %s', 271 wake_elog, wake_syslog) 272 return None 273 raise sys_power.SpuriousWakeupError('Spurious wake in S3: %s | %s' 274 % (wake_elog, wake_syslog)) 275 if self._get_board() in ['lumpy', 'stumpy', 'kiev']: 276 logging.debug('RTC read failure (crosbug/36004), dumping nvram:\n' + 277 utils.system_output('mosys nvram dump', ignore_status=True)) 278 return None 279 raise error.TestError('Broken RTC timestamp: ' + 280 utils.read_file(self.HWCLOCK_FILE)) 281 282 283 def _firmware_resume_time(self): 284 """Calculate seconds for firmware resume from logged TSC. (x86 only)""" 285 if utils.get_arch() not in ['i686', 'x86_64']: 286 # TODO: support this on ARM somehow 287 return 0 288 regex_freeze = re.compile(r'PM: resume from suspend-to-idle') 289 regex_tsc = re.compile(r'TSC at resume: (\d+)$') 290 freq = 1000 * int(utils.read_one_line( 291 '/sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq')) 292 for line in reversed(self._logs): 293 match_freeze = regex_freeze.search(line) 294 if match_freeze: 295 logging.info('fw resume time zero due to suspend-to-idle\n') 296 return 0 297 match_tsc = regex_tsc.search(line) 298 if match_tsc: 299 return float(match_tsc.group(1)) / freq 300 301 raise error.TestError('Failed to find TSC resume value in syslog.') 302 303 304 def _device_resume_time(self): 305 """Read amount of seconds for overall device resume from syslog.""" 306 regex = re.compile(r'PM: resume of devices complete after ([0-9.]+)') 307 for line in reversed(self._logs): 308 match = regex.search(line) 309 if match: 310 return float(match.group(1)) / 1000 311 312 raise error.TestError('Failed to find device resume time in syslog.') 313 314 315 def _get_phase_times(self): 316 phase_times = [] 317 regex = re.compile(r'PM: (\w+ )?(resume|suspend) of devices complete') 318 for line in self._logs: 319 match = regex.search(line) 320 if match: 321 ts = cros_logging.extract_kernel_timestamp(line) 322 phase = match.group(1) 323 if not phase: 324 phase = 'REG' 325 phase_times.append((phase.upper(), ts)) 326 return sorted(phase_times, key = lambda entry: entry[1]) 327 328 329 def _get_phase(self, ts, phase_table, dev): 330 for entry in phase_table: 331 #checking if timestamp was before that phase's cutoff 332 if ts < entry[1]: 333 return entry[0] 334 raise error.TestError('Device %s has a timestamp after all devices %s', 335 dev, 'had already resumed') 336 337 338 def _individual_device_times(self, start_resume): 339 """Return dict of individual device suspend and resume times.""" 340 self.device_times.append(dict()) 341 dev_details = collections.defaultdict(dict) 342 regex = re.compile(r'call ([^ ]+)\+ returned 0 after ([0-9]+) usecs') 343 phase_table = self._get_phase_times() 344 for line in self._logs: 345 match = regex.search(line) 346 if match: 347 device = match.group(1).replace(':', '-') 348 key = 'seconds_dev_' + device 349 secs = float(match.group(2)) / 1e6 350 ts = cros_logging.extract_kernel_timestamp(line) 351 if ts > start_resume: 352 key += '_resume' 353 else: 354 key += '_suspend' 355 #looking if we're in a special phase 356 phase = self._get_phase(ts, phase_table, device) 357 dev = dev_details[key] 358 if phase in dev: 359 logging.warning('Duplicate %s entry for device %s, +%f', phase, 360 device, secs) 361 dev[phase] += secs 362 else: 363 dev[phase] = secs 364 365 for dev_key, dev in dev_details.iteritems(): 366 total_secs = sum(dev.values()) 367 self.device_times[-1][dev_key] = total_secs 368 report = '%s: %f TOT' % (dev_key, total_secs) 369 for phase in dev.keys(): 370 if phase is 'REG': 371 continue 372 report += ', %f %s' % (dev[phase], phase) 373 logging.debug(report) 374 375 376 def _identify_driver(self, device): 377 """Return the driver name of a device (or "unknown").""" 378 for path, subdirs, _ in os.walk('/sys/devices'): 379 if device in subdirs: 380 node = os.path.join(path, device, 'driver') 381 if not os.path.exists(node): 382 return "unknown" 383 return os.path.basename(os.path.realpath(node)) 384 else: 385 return "unknown" 386 387 388 def _check_for_errors(self, ignore_kernel_warns): 389 """Find and identify suspend errors. 390 391 @param ignore_kernel_warns: Ignore kernel errors. 392 393 @returns: True iff we should retry. 394 395 @raises: 396 sys_power.KernelError: for non-whitelisted kernel failures. 397 sys_power.SuspendTimeout: took too long to enter suspend. 398 sys_power.SpuriousWakeupError: woke too soon from suspend. 399 sys_power.SuspendFailure: unidentified failure. 400 """ 401 warning_regex = re.compile(r' kernel: \[.*WARNING:') 402 abort_regex = re.compile(r' kernel: \[.*Freezing of tasks abort' 403 r'| powerd_suspend\[.*Cancel suspend at kernel' 404 r'| kernel: \[.*PM: Wakeup pending, aborting suspend') 405 # rsyslogd can put this out of order with dmesg, so track in variable 406 fail_regex = re.compile(r'powerd_suspend\[\d+\]: Error') 407 failed = False 408 409 # TODO(scottz): warning_monitor crosbug.com/38092 410 log_len = len(self._logs) 411 for i in xrange(log_len): 412 line = self._logs[i] 413 if warning_regex.search(line): 414 # match the source file from the WARNING line, and the 415 # actual error text by peeking one or two lines below that 416 src = cros_logging.strip_timestamp(line) 417 text = '' 418 if i+1 < log_len: 419 text = cros_logging.strip_timestamp(self._logs[i + 1]) 420 if i+2 < log_len: 421 text += '\n' + cros_logging.strip_timestamp( 422 self._logs[i + 2]) 423 for p1, p2 in sys_power.KernelError.WHITELIST: 424 if re.search(p1, src) and re.search(p2, text): 425 logging.info('Whitelisted KernelError: %s', src) 426 break 427 else: 428 if ignore_kernel_warns: 429 logging.warn('Non-whitelisted KernelError: %s', src) 430 else: 431 raise sys_power.KernelError("%s\n%s" % (src, text)) 432 if abort_regex.search(line): 433 wake_source = 'unknown' 434 match = re.search(r'last active wakeup source: (.*)$', 435 '\n'.join(self._logs[i-5:i+3]), re.MULTILINE) 436 if match: 437 wake_source = match.group(1) 438 driver = self._identify_driver(wake_source) 439 for b, w in sys_power.SpuriousWakeupError.S0_WHITELIST: 440 if (re.search(b, utils.get_board()) and 441 re.search(w, wake_source)): 442 logging.warning('Whitelisted spurious wake before ' 443 'S3: %s | %s', wake_source, driver) 444 return True 445 if "rtc" in driver: 446 raise sys_power.SuspendTimeout('System took too ' 447 'long to suspend.') 448 raise sys_power.SpuriousWakeupError('Spurious wake ' 449 'before S3: %s | %s' % (wake_source, driver)) 450 if fail_regex.search(line): 451 failed = True 452 453 if failed: 454 raise sys_power.SuspendFailure('Unidentified problem.') 455 return False 456 457 458 def _arc_resume_ts(self, retries=3): 459 """Parse arc logcat for arc resume timestamp. 460 461 @param retries: retry if the expected log cannot be found in logcat. 462 463 @returns: a float representing arc resume timestamp in CPU seconds 464 starting from the last boot if arc logcat resume log is parsed 465 correctly; otherwise 'unknown'. 466 467 """ 468 command = 'android-sh -c "logcat -v monotonic -t 300 *:silent' \ 469 ' ArcPowerManagerService:D"' 470 regex_resume = re.compile(r'^\s*(\d+\.\d+).*ArcPowerManagerService: ' 471 'Suspend is over; resuming all apps$') 472 for retry in xrange(retries + 1): 473 arc_logcat = utils.system_output(command, ignore_status=False) 474 arc_logcat = arc_logcat.splitlines() 475 resume_ts = 0 476 for line in arc_logcat: 477 match_resume = regex_resume.search(line) 478 # ARC logcat is cleared before suspend so the first ARC resume 479 # timestamp is the one we are looking for. 480 if match_resume: 481 return float(match_resume.group(1)) 482 time.sleep(0.005 * 2**retry) 483 else: 484 logging.error('ARC did not resume correctly.') 485 return 'unknown' 486 487 488 def suspend(self, duration=10, ignore_kernel_warns=False, 489 measure_arc=False): 490 """ 491 Do a single suspend for 'duration' seconds. Estimates the amount of time 492 it takes to suspend for a board (see _SUSPEND_DELAY), so the actual RTC 493 wakeup delay will be longer. Returns None on errors, or raises the 494 exception when _throw is set. Returns a dict of general measurements, 495 or a tuple (general_measurements, individual_device_times) when 496 _device_times is set. 497 498 @param duration: time in seconds to do a suspend prior to waking. 499 @param ignore_kernel_warns: Ignore kernel errors. Defaults to false. 500 """ 501 502 if power_utils.get_sleep_state() == 'freeze': 503 self._s0ix_residency_stats = power_status.S0ixResidencyStats() 504 505 try: 506 iteration = len(self.failures) + len(self.successes) + 1 507 # Retry suspend in case we hit a known (whitelisted) bug 508 for _ in xrange(10): 509 # Clear powerd_suspend RTC timestamp, to avoid stale results. 510 utils.open_write_close(self.HWCLOCK_FILE, '') 511 self._reset_logs() 512 utils.system('sync') 513 board_delay = self._SUSPEND_DELAY.get(self._get_board(), 514 self._DEFAULT_SUSPEND_DELAY) 515 # Clear the ARC logcat to make parsing easier. 516 if measure_arc: 517 command = 'android-sh -c "logcat -c"' 518 utils.system(command, ignore_status=False) 519 try: 520 alarm = self._suspend(duration + board_delay) 521 except sys_power.SpuriousWakeupError: 522 # might be another error, we check for it ourselves below 523 alarm = self._ALARM_FORCE_EARLY_WAKEUP 524 525 if os.path.exists('/sys/firmware/log'): 526 for msg in re.findall(r'^.*ERROR.*$', 527 utils.read_file('/sys/firmware/log'), re.M): 528 for board, pattern in sys_power.FirmwareError.WHITELIST: 529 if (re.search(board, utils.get_board()) and 530 re.search(pattern, msg)): 531 logging.info('Whitelisted FW error: ' + msg) 532 break 533 else: 534 firmware_log = os.path.join(self._logdir, 535 'firmware.log.' + str(iteration)) 536 shutil.copy('/sys/firmware/log', firmware_log) 537 logging.info('Saved firmware log: ' + firmware_log) 538 raise sys_power.FirmwareError(msg.strip('\r\n ')) 539 540 self._update_logs() 541 if not self._check_for_errors(ignore_kernel_warns): 542 hwclock_ts = self._hwclock_ts(alarm) 543 if hwclock_ts: 544 break 545 546 else: 547 raise error.TestWarn('Ten tries failed due to whitelisted bug') 548 549 # calculate general measurements 550 start_resume = self._ts('start_resume_time') 551 kernel_down = (self._ts('end_suspend_time') - 552 self._ts('start_suspend_time')) 553 kernel_up = self._ts('end_resume_time') - start_resume 554 devices_up = self._device_resume_time() 555 total_up = hwclock_ts - alarm 556 firmware_up = self._firmware_resume_time() 557 board_up = total_up - kernel_up - firmware_up 558 try: 559 cpu_up = self._ts('cpu_ready_time', 0) - start_resume 560 except error.TestError: 561 # can be missing on non-SMP machines 562 cpu_up = None 563 if total_up > self._MAX_RESUME_TIME: 564 raise error.TestError('Sanity check failed: missed RTC wakeup.') 565 566 logging.info('Success(%d): %g down, %g up, %g board, %g firmware, ' 567 '%g kernel, %g cpu, %g devices', 568 iteration, kernel_down, total_up, board_up, 569 firmware_up, kernel_up, cpu_up, devices_up) 570 571 if hasattr(self, '_s0ix_residency_stats'): 572 s0ix_residency_secs = \ 573 self._s0ix_residency_stats.\ 574 get_accumulated_residency_secs() 575 if not s0ix_residency_secs: 576 raise sys_power.S0ixResidencyNotChanged( 577 'S0ix residency did not change.') 578 logging.info('S0ix residency : %d secs.', s0ix_residency_secs) 579 580 successful_suspend = { 581 'seconds_system_suspend': kernel_down, 582 'seconds_system_resume': total_up, 583 'seconds_system_resume_firmware': firmware_up + board_up, 584 'seconds_system_resume_firmware_cpu': firmware_up, 585 'seconds_system_resume_firmware_ec': board_up, 586 'seconds_system_resume_kernel': kernel_up, 587 'seconds_system_resume_kernel_cpu': cpu_up, 588 'seconds_system_resume_kernel_dev': devices_up, 589 } 590 591 if measure_arc: 592 successful_suspend['seconds_system_resume_arc'] = \ 593 self._arc_resume_ts() - start_resume 594 595 self.successes.append(successful_suspend) 596 597 if hasattr(self, 'device_times'): 598 self._individual_device_times(start_resume) 599 return (self.successes[-1], self.device_times[-1]) 600 else: 601 return self.successes[-1] 602 603 except sys_power.SuspendFailure as ex: 604 message = '%s(%d): %s' % (type(ex).__name__, iteration, ex) 605 logging.error(message) 606 self.failures.append(ex) 607 if self._throw: 608 if type(ex).__name__ in ['KernelError', 'SuspendTimeout']: 609 raise error.TestWarn(message) 610 else: 611 raise error.TestFail(message) 612 return None 613 614 615 def finalize(self): 616 """Restore normal environment (not turning 3G back on for now...)""" 617 if os.path.exists(self.HWCLOCK_FILE): 618 os.remove(self.HWCLOCK_FILE) 619 if self._restart_tlsdated: 620 utils.system('initctl start tlsdated') 621 if self._reset_pm_print_times: 622 self._set_pm_print_times(False) 623 if hasattr(self, '_power_pref_changer'): 624 self._power_pref_changer.finalize() 625 626 627 def __del__(self): 628 self.finalize() 629