1# Copyright (c) 2013 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, subprocess, threading
6import common
7from autotest_lib.client.bin import test, utils
8from autotest_lib.client.common_lib import error
9
10
11class hardware_Badblocks(test.test):
12    """
13    Runs badblocks on the root partition that is not being used.
14
15    """
16
17    version = 1
18
19    # Define output that is expected from a successful badblocks run.
20    _EXPECTED_BADBLOCKS_OUTPUT = (
21            'Pass completed, 0 bad blocks found. (0/0/0 errors)')
22
23    # Define Linux badblocks utility name.
24    _BADBLOCKS = 'badblocks'
25
26    # Define variables to store some statistics of the runs.
27    _pass_count = 0
28    _fail_count = 0
29    _longest_runtime = 0
30
31
32    def _get_sector_size(self, dev):
33        """
34        Finds block device's sector size in bytes.
35
36        @return the sector size.
37
38        """
39
40        argv = ('parted ' + dev + ' print | grep "Sector size" | awk -F ' +
41                '"/" \'{print $3}\' | sed \'$s/.$//\'')
42
43        return utils.system_output(argv)
44
45
46    def _timeout(self, badblocks_proc):
47        """
48        Timeout callback for the badblocks process.
49
50        Kills badblocks process if still running and fails test.
51
52        """
53
54        # Kill badblocks, report if not killed, log any exceptions.
55        if badblocks_proc.poll() == None:
56            try:
57                logging.info('badblocks taking too long---sending SIGKILL')
58                badblocks_proc.kill()
59            except Exception as e:
60                logging.info('%s', e)
61            finally:
62                # name of the kernel function in which the process is sleeping.
63                argv = ('ps eopid,fname,wchan | grep ' + self._BADBLOCKS +
64                        ' | awk \'{print $3}\'')
65                waiton = utils.system_output(argv)
66                if waiton:
67                    logging.info('badblocks is waiting on %s', waiton)
68                raise error.TestError('Error: badblocks timed out.')
69
70
71    def _run_badblocks(self, dev, sector_size, tmout):
72        """
73        Runs badblocks.
74
75        """
76
77        # Run badblocks on the selected partition, with parameters:
78        # -s = show progress
79        # -v = verbose (print error count)
80        # -w = destructive write+read test
81        # -b = block size (set equal to sector size)
82        argv = [self._BADBLOCKS, '-svw', '-d', str(sector_size), dev]
83        msg = 'Running: ' + ' '.join(map(str, argv))
84        logging.info(msg)
85        badblocks_proc = subprocess.Popen(
86                argv,
87                shell=False,
88                stderr=subprocess.STDOUT, # Combine stderr with stdout.
89                stdout=subprocess.PIPE)
90
91        # Start timeout timer thread.
92        t = threading.Timer(tmout, self._timeout, [badblocks_proc])
93        t.start()
94
95        # Get badblocks output.
96        stdout, _ = badblocks_proc.communicate()
97
98        # Stop timer if badblocks has finished.
99        t.cancel()
100
101        # Check badblocks exit status.
102        if badblocks_proc.returncode != 0:
103            raise error.TestError('badblocks returned with code: %s',
104                                  badblocks_proc.returncode)
105
106        # Parse and log badblocks output.
107        logging.info('badblocks output:')
108        lines = stdout.split('\n')
109        del lines[-1] # Remove blank line at end.
110        logging.info(lines[0])
111        logging.info(lines[1])
112        # Log the progress of badblocks (line 2 onwards, minus last line).
113        for line in lines[2:-1]:
114            # replace backspace characters with a newline character.
115            line = re.sub(r'[\b]+', '\n', line)
116            # Log test pattern info.
117            pattern_info = line[:line.find(':') + 1]
118            logging.info('%s', pattern_info)
119            sublines = line[line.find(':') + 2:].split('\n')
120            for subline in sublines:
121                logging.info('%s', subline)
122        # Log result (last line).
123        logging.info(lines[-1])
124
125        # Get run time in seconds.
126        min_sec = re.match(r'(\w+):(\w+)', lines[-2].split()[-4])
127        runtime = int(min_sec.group(1)) * 60 + int(min_sec.group(2))
128
129        # Update longest run time.
130        if self._longest_runtime < runtime:
131            self._longest_runtime = runtime
132
133        # Check badblocks result.
134        result = lines[-1].strip()
135        if result != self._EXPECTED_BADBLOCKS_OUTPUT:
136            self._fail_count += 1
137            return
138        self._pass_count += 1
139
140
141    def run_once(self, iters=1, tmout=60 * 60):
142        """
143        Executes test.
144
145        @param iters: Number of times to run badblocks.
146        @param tmout: Time allowed badblocks to run before killing it.
147                      (Default time is 60 minutes.)
148
149        """
150
151        # Log starting message.
152        logging.info('Statring hardware_Badblocks Test.')
153        logging.info('Iterations: %d', iters)
154        logging.info('badblocks Timeout (sec): %d', tmout)
155
156        # Determine which device and partition to use.
157        logging.info('Determine unused root partition to test on:')
158        dev = utils.get_free_root_partition()
159        logging.info('Testing on ' + dev)
160
161        # Get block device's sector size.
162        logging.info('Determine block device sector size:')
163        sector_size = self._get_sector_size(utils.get_root_device())
164        logging.info('Sector size (bytes): ' + sector_size)
165
166        # Get partition size.
167        logging.info('Determine partition size:')
168        part_size = utils.get_disk_size(dev)
169        logging.info('Partition size (bytes): %s', part_size)
170
171        # Run badblocks.
172        for i in range(iters):
173            logging.info('Starting iteration %d', i)
174            self._run_badblocks(dev, sector_size, tmout)
175
176        # Report statistics.
177        logging.info('Total pass: %d', self._pass_count)
178        logging.info('Total fail: %d', self._fail_count)
179        stats = {}
180        stats['ea_badblocks_runs'] = iters
181        stats['ea_passed_count'] = self._pass_count
182        stats['ea_failed_count'] = self._fail_count
183        stats['sec_longest_run'] = self._longest_runtime
184        # TODO: change write_perf_keyval() to output_perf_value() as soon as
185        # autotest is ready for it.
186        self.write_perf_keyval(stats)
187
188        # Report test pass/fail.
189        if self._pass_count != iters:
190            raise error.TestFail('One or more runs found bad blocks on'
191                                 ' storage device.')
192