• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1# Copyright 2014 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
5import logging, re, time
6
7from autotest_lib.client.common_lib import error
8from autotest_lib.server.cros.faft.firmware_test import FirmwareTest
9
10
11class firmware_EventLog(FirmwareTest):
12    """
13    Test to ensure eventlog is written on boot and suspend/resume.
14    """
15    version = 1
16
17    _TIME_FORMAT = '%Y-%m-%d %H:%M:%S'
18
19    def initialize(self, host, cmdline_args):
20        super(firmware_EventLog, self).initialize(host, cmdline_args)
21        self.switcher.setup_mode('normal')
22
23    def _has_event(self, pattern):
24        return bool(filter(re.compile(pattern).search, self._events))
25
26    def _gather_events(self):
27        entries = self.faft_client.system.run_shell_command_get_output(
28                'mosys eventlog list')
29        now = self._now()
30        self._events = []
31        for line in reversed(entries):
32            _, time_string, event = line.split(' | ', 2)
33            timestamp = time.strptime(time_string, self._TIME_FORMAT)
34            if timestamp > now:
35                logging.error('Found prophecy: "%s"', line)
36                raise error.TestFail('Event timestamp lies in the future')
37            if timestamp < self._cutoff_time:
38                logging.debug('Event "%s" too early, stopping search', line)
39                break
40            logging.info('Found event: "%s"', line)
41            self._events.append(event)
42
43    # This assumes that Linux and the firmware use the same RTC. mosys converts
44    # timestamps to localtime, and so do we (by calling date without --utc).
45    def _now(self):
46        time_string = self.faft_client.system.run_shell_command_get_output(
47                'date +"%s"' % self._TIME_FORMAT)[0]
48        logging.debug('Current local system time on DUT is "%s"', time_string)
49        return time.strptime(time_string, self._TIME_FORMAT)
50
51    def run_once(self):
52        if not self.faft_config.has_eventlog:
53            raise error.TestNAError('This board has no eventlog support.')
54
55        logging.info('Verifying eventlog behavior on normal mode boot')
56        self._cutoff_time = self._now()
57        self.switcher.mode_aware_reboot()
58        self.check_state((self.checkers.crossystem_checker, {
59                              'devsw_boot': '0',
60                              'mainfw_type': 'normal',
61                              }))
62        self._gather_events()
63        if not self._has_event(r'System boot'):
64            raise error.TestError('No "System boot" event on normal boot.')
65        # ' Wake' to match 'FW Wake' and 'ACPI Wake' but not 'Wake Source'
66        if self._has_event(r'Developer Mode|Recovery Mode|Sleep| Wake'):
67            raise error.TestError('Incorrect event logged on normal boot.')
68
69        logging.debug('Transitioning to dev mode for next test')
70        self.switcher.reboot_to_mode(to_mode='dev')
71
72        logging.info('Verifying eventlog behavior on developer mode boot')
73        self._cutoff_time = self._now()
74        self.switcher.mode_aware_reboot()
75        self.check_state((self.checkers.crossystem_checker, {
76                              'devsw_boot': '1',
77                              'mainfw_type': 'developer',
78                              }))
79        self._gather_events()
80        if (not self._has_event(r'System boot') or
81            not self._has_event(r'Chrome OS Developer Mode')):
82            raise error.TestError('Missing required event on dev mode boot.')
83        if self._has_event(r'Recovery Mode|Sleep| Wake'):
84            raise error.TestError('Incorrect event logged on dev mode boot.')
85
86        logging.debug('Transitioning back to normal mode for final tests')
87        self.switcher.reboot_to_mode(to_mode='normal')
88
89        logging.info('Verifying eventlog behavior in recovery mode')
90        self._cutoff_time = self._now()
91        self.switcher.reboot_to_mode(to_mode='rec', wait_for_dut_up=False)
92        self.switcher.wait_for_client_offline()
93        time.sleep(self.faft_config.firmware_screen)
94        self.switcher.mode_aware_reboot(sync_before_boot=False)
95        self.check_state((self.checkers.crossystem_checker, {
96                              'devsw_boot': '0',
97                              'mainfw_type': 'normal',
98                              }))
99        self._gather_events()
100        if (not self._has_event(r'System boot') or
101            not self._has_event(r'Chrome OS Recovery Mode \| Recovery Button')):
102            raise error.TestError('Missing required event in recovery mode.')
103        if self._has_event(r'Developer Mode|Sleep|FW Wake|ACPI Wake \| S3'):
104            raise error.TestError('Incorrect event logged in recovery mode.')
105
106        logging.info('Verifying eventlog behavior on suspend/resume')
107        self._cutoff_time = self._now()
108        self.faft_client.system.run_shell_command(
109                'powerd_dbus_suspend -wakeup_timeout=10')
110        time.sleep(5)   # a little slack time for powerd to write the 'Wake'
111        self._gather_events()
112        if ((not self._has_event(r'^Wake') or not self._has_event(r'Sleep')) and
113            (not self._has_event(r'ACPI Enter \| S3') or
114             not self._has_event(r'ACPI Wake \| S3'))):
115            raise error.TestError('Missing required event on suspend/resume.')
116        if self._has_event(r'System |Developer Mode|Recovery Mode'):
117            raise error.TestError('Incorrect event logged on suspend/resume.')
118