1# Copyright (c) 2011 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
6import time
7
8from autotest_lib.client.common_lib import error
9from autotest_lib.server.cros.faft.firmware_test import FirmwareTest
10
11
12class firmware_DevScreenTimeout(FirmwareTest):
13    """
14    Servo based developer firmware screen timeout test.
15
16    When booting in developer mode, the firmware shows a screen to warn user
17    the disk image is not secured. If a user press Ctrl-D or a timeout reaches,
18    it will boot to developer mode. This test is to verify the timeout period.
19
20    This test tries to boot the system in developer mode twice.
21    The first one will repeatedly press Ctrl-D on booting in order to reduce
22    the time on developer warning screen. The second one will do nothing and
23    wait the developer screen timeout. The time difference of these two boots
24    is close to the developer screen timeout.
25    """
26    version = 1
27
28    # We accept 5s timeout margin as we need 5s to ensure client is offline.
29    # If the margin is too small and firmware initialization is too fast,
30    # the test will fail incorrectly.
31    TIMEOUT_MARGIN = 5
32    # Time for the concerned files to be added to the filesystem.
33    RUN_SHELL_READY_TIME_MARGIN = 10
34
35    fw_time_record = {}
36
37    def record_dev_screen_timestamp(self):
38        """Record timestamp when developer screen appears"""
39
40        timestamps_file = '/var/log/bios_times.txt'
41        timestamp_name = 'vboot select&load kernel'
42        sed_expression = 's/[0-9]*:%s[[:blank:]]*\([0-9,]*\).*/\\1/p' % (
43            timestamp_name)
44        cmd = 'sed -n \'%s\' %s | sed \'s/,//g\'' % (
45            sed_expression, timestamps_file)
46        time.sleep(self.RUN_SHELL_READY_TIME_MARGIN)
47        result = self.faft_client.system.run_shell_command_get_output(
48                cmd)
49        if result:
50            [dev_screen_ts] = result
51            self.fw_time_record['dev_screen_appear_ts'] = (
52                (float(dev_screen_ts) / 1000000) + 0.7)
53            logging.info("Developer screen timestamp is %.2f",
54                self.fw_time_record['dev_screen_appear_ts'])
55        else:
56            logging.info("Failed to get developer screen appear timestamp, fallback to 0")
57            self.fw_time_record['dev_screen_appear_ts'] = 0
58
59    def record_fw_boot_time(self, tag):
60        """Record the current firmware boot time with the tag.
61
62        @param tag: A tag about this boot.
63        @raise TestError: If the firmware-boot-time file does not exist.
64        """
65        elapsed_time = 0
66        fw_time = 0
67        # Try getting the firmware boot time for 10 seconds at 1 second retry
68        # interval. This is required to allow the send_boot_metrics upstart job
69        # to create that file.
70        while elapsed_time < self.RUN_SHELL_READY_TIME_MARGIN:
71            time.sleep(1)
72            status = self.faft_client.system.run_shell_command_get_status(
73                    '[ -s /tmp/firmware-boot-time ]')
74            if status == 0:
75                [fw_time] = self.faft_client.system.run_shell_command_get_output(
76                        'cat /tmp/firmware-boot-time')
77                break
78            elapsed_time += 1
79
80        if fw_time and elapsed_time < self.RUN_SHELL_READY_TIME_MARGIN:
81            logging.info('Got firmware boot time [%s]: %s', tag, fw_time)
82            self.fw_time_record[tag] = float(fw_time)
83        else:
84            raise error.TestError('Failed to get the firmware boot time.')
85
86    def check_timeout_period(self):
87        """Check the firmware screen timeout period matches our spec.
88
89        @raise TestFail: If the timeout period does not match our spec.
90        """
91        # On tablets/detachables, eliminate the time taken for pressing volume
92        # down button (HOLD_VOL_DOWN_BUTTON_BYPASS + 0.1) to calculate the
93        # firmware boot time of quick dev boot.
94        if self.faft_config.mode_switcher_type == 'tablet_detachable_switcher':
95            self.fw_time_record['quick_bypass_boot'] -= \
96                            (self.switcher.HOLD_VOL_DOWN_BUTTON_BYPASS + 0.1)
97            logging.info(
98                    "Firmware boot time [quick_bypass_boot] after "
99                    "eliminating the volume down button press time "
100                    "(%.1f seconds): %s",
101                    self.switcher.HOLD_VOL_DOWN_BUTTON_BYPASS + 0.1,
102                    self.fw_time_record['quick_bypass_boot'])
103        got_timeout = (self.fw_time_record['timeout_boot'] -
104                       self.fw_time_record['quick_bypass_boot'])
105        logging.info('Estimated developer firmware timeout: %s', got_timeout)
106
107        if (abs(got_timeout - self.faft_config.dev_screen_timeout) >
108                    self.TIMEOUT_MARGIN):
109            raise error.TestFail(
110                    'The developer firmware timeout does not match our spec: '
111                    'expected %.2f +/- %.2f but got %.2f.' %
112                    (self.faft_config.dev_screen_timeout, self.TIMEOUT_MARGIN,
113                     got_timeout))
114
115    def initialize(self, host, cmdline_args):
116        super(firmware_DevScreenTimeout, self).initialize(host, cmdline_args)
117        # NA error check point for this test
118        if self.faft_config.mode_switcher_type not in (
119                'keyboard_dev_switcher', 'tablet_detachable_switcher',
120                'menu_switcher'):
121            raise error.TestNAError("This test is only valid on devices with "
122                                    "screens.")
123        # This test is run on developer mode only.
124        self.switcher.setup_mode('dev')
125        self.setup_usbkey(usbkey=False)
126
127    def run_once(self):
128        """Runs a single iteration of the test."""
129        logging.info("Always expected developer mode firmware A boot.")
130        self.check_state((self.checkers.crossystem_checker, {
131                'devsw_boot': '1',
132                'mainfw_act': 'A',
133                'mainfw_type': 'developer',
134        }))
135
136        # To add an extra reboot before the measurement
137        # to avoid TPM reset too long
138        self.switcher.simple_reboot()
139        self.switcher.wait_for_client()
140
141        logging.info("Reboot the device, do nothing and wait for screen "
142                     "timeout. And then record the firmware boot time and "
143                     "developer screen timestamp.")
144        self.switcher.simple_reboot()
145        self.switcher.wait_for_client()
146
147        # Record developer screen timestamp
148        self.record_dev_screen_timestamp()
149        # Record the boot time of firmware screen timeout.
150        self.record_fw_boot_time('timeout_boot')
151
152        # Measure firmware boot time with developer screen bypass
153        logging.info("Reboot and bypass the Developer warning screen "
154                     "immediately.")
155        self.switcher.simple_reboot()
156        time.sleep(self.fw_time_record['dev_screen_appear_ts'])
157        self.switcher.bypass_dev_mode()
158        self.switcher.wait_for_client()
159        logging.info("Record the firmware boot time without waiting for "
160                     "firmware screen.")
161        self.record_fw_boot_time('quick_bypass_boot')
162
163        logging.info("Check the firmware screen timeout matches our spec.")
164        self.check_timeout_period()
165