1##########################################################################
2# Copyright (c) 2009, 2010, 2016, ETH Zurich.
3# All rights reserved.
4#
5# This file is distributed under the terms in the attached LICENSE file.
6# If you do not find this file, copies can be found by writing to:
7# ETH Zurich D-INFK, Universitaetstr 6, CH-8092 Zurich. Attn: Systems Group.
8##########################################################################
9
10import os, shutil, select, datetime, pexpect, tempfile, signal
11from pexpect import fdpexpect
12import barrelfish, debug
13from tests import Test
14from harness import Harness
15
16RAW_TEST_OUTPUT_FILENAME = Harness.RAW_FILE_NAME
17DEFAULT_TEST_TIMEOUT = datetime.timedelta(seconds=600)
18DEFAULT_BOOT_TIMEOUT = datetime.timedelta(seconds=300)
19AFTER_FINISH_TIMEOUT = datetime.timedelta(seconds=30)
20TEST_NO_OUTPUT_LINE = '[Error: could not read output from test]\n'
21TEST_TIMEOUT_LINE = '[Error: test timed out]\n'
22BOOT_TIMEOUT_LINE_RETRY = '[Error: boot timed out, retrying...]\n'
23BOOT_TIMEOUT_LINE_FAIL = '[Error: boot timed out, retry limit reached]\n'
24MAX_BOOT_ATTEMPTS = 3 # maximum number of times to attempt booting before giving up
25
26class TimeoutError(Exception):
27    def __init__(self, when=None):
28        self.when = when
29    def __str__(self):
30        return 'timeout occurred%s' % (': ' + self.when if self.when else '')
31
32class SignalledFdSpawn(fdpexpect.fdspawn):
33
34    def read_nonblocking(self, size=1, timeout=None):
35        """ This method uses OS signals to implement timeouts """
36        # Get timeout from instance
37        if timeout == -1:
38            timeout = self.timeout
39
40        if timeout is not None:
41            # Assert there is no other alarm signal handler installed
42            assert(signal.getsignal(signal.SIGALRM) == signal.SIG_DFL)
43
44            # Timeout 0 actually cancels the alarm
45            assert(int(timeout) > 0)
46            def timeout_handler(frame,signum):
47                raise pexpect.TIMEOUT("Signalled Timeout")
48
49            # Install handler and setup alarm
50            signal.signal(signal.SIGALRM, timeout_handler)
51            signal.alarm(int(timeout))
52
53        try:
54            return super(SignalledFdSpawn, self).read_nonblocking(size, None)
55        finally:
56            # Remove our handler
57            signal.signal(signal.SIGALRM, signal.SIG_DFL)
58
59class TestCommon(Test):
60    name = None # should be overridden
61
62    def __init__(self, options):
63        super(TestCommon, self).__init__(options)
64        self.timeout = None # current timeout (as absolute datetime)
65        self.test_timeout_delta = DEFAULT_TEST_TIMEOUT # timeout delta for next test
66        self.boot_phase = True # are we waiting for machine boot or test output?
67        self.boot_attempts = 0 # how many times did we try to boot?
68
69        # The default should be True, it causes harness to include extra
70        # console output that appears after the test returns true for is_finished.
71        # However, many tests currently rely on the the last line being exactly
72        # the one that caused is_finished to become true. So disable
73        # this for now by default
74        self.read_after_finished = False
75
76    def _setup_harness_dir(self, build, machine):
77        dest_dir = machine.get_tftp_dir()
78        debug.verbose('installing to %s' % dest_dir)
79        if os.access(dest_dir, os.F_OK):
80            debug.verbose('clearing out %s' % dest_dir)
81            for e in os.listdir(dest_dir):
82                p = os.path.join(dest_dir, e)
83                if os.path.isdir(p):
84                    shutil.rmtree(p, ignore_errors=True)
85                elif not e.startswith('.nfs'):
86                    os.unlink(p)
87        else:
88            debug.verbose('creating %s' % dest_dir)
89            os.makedirs(dest_dir)
90        return dest_dir
91
92    def setup(self, build, machine, testdir):
93        # build the default set of targets
94        targets = self.get_build_targets(build, machine)
95        # set custom test timeout if machine specifies one
96        test_timeout_secs = machine.get_test_timeout()
97        if not test_timeout_secs:
98            test_timeout_secs = DEFAULT_TEST_TIMEOUT
99        else:
100            test_timeout_secs = datetime.timedelta(seconds=test_timeout_secs)
101        self.test_timeout_delta = test_timeout_secs
102        self.testdir = testdir
103        build.build(targets)
104
105        # lock the machine
106        machine.lock()
107        machine.setup()
108
109        # setup the harness dir and install there
110        dest_dir = self._setup_harness_dir(build, machine)
111        build.install(targets, dest_dir)
112
113    def get_modules(self, build, machine):
114        return machine.default_bootmodules()
115
116    def get_build_targets(self, build, machine):
117        return self.get_modules(build, machine).get_build_targets()
118
119    def set_timeout(self, delta=DEFAULT_TEST_TIMEOUT):
120        self.test_timeout_delta = delta
121        if not self.boot_phase:
122            if delta:
123                debug.verbose('setting timeout for %s' % delta)
124                self.timeout = datetime.datetime.now() + delta
125            else:
126                debug.verbose('cancelling timeout')
127                self.timeout = None
128
129    def boot(self, machine, modules):
130        machine.set_bootmodules(modules)
131        self.boot_attempts = 0
132        self.reboot(machine)
133
134    def reboot(self, machine):
135        # retry a failed boot, without changing the modules
136        machine.reboot()
137        self.boot_phase = True
138        self.boot_attempts += 1
139        timeout_secs = machine.get_boot_timeout()
140        if timeout_secs:
141            self.timeout = (datetime.datetime.now()
142                                 + datetime.timedelta(seconds=timeout_secs))
143        else:
144            self.timeout = datetime.datetime.now() + DEFAULT_BOOT_TIMEOUT
145
146    def get_finish_string(self):
147        # default output from a test program when it completes
148        # should be overridden by subclasses
149        return "client done"
150
151    def is_finished(self, line):
152        # Exit test when we get an assertion failure or an abort, rather than
153        # waiting for timeout
154        return self.get_finish_string() in line or \
155               line.startswith("Assertion failed on core") or \
156               line.find("PANIC!") > 0 or \
157               line.startswith("Aborted")
158
159    def is_booted(self, line):
160        # early boot output from Barrelfish kernel
161        return "Barrelfish CPU driver starting" in line
162
163    def process_line(self, rawline):
164        """Can be used by subclasses to hook into the raw output stream."""
165        pass
166
167    def _readline(self, fh, timeout=None):
168        """ if given, timeout parameter overrides self.timeout for call """
169        if timeout is None:
170            timeout = self.timeout
171
172        # standard blocking readline if no timeout is set
173        if not timeout:
174            return fh.readline()
175
176        line = ''
177        fhArray = [fh]
178        while not line.endswith('\n'):
179            # wait until there is something to read, with a timeout
180            (readlist, _, _) = select_timeout(timeout, fhArray)
181            if not readlist:
182                # if we have some partial data, return that first!
183                # we'll be called again, and the next time can raise the error
184                if line:
185                    return line
186                elif self.boot_phase:
187                    raise TimeoutError('waiting for victim to boot')
188                else:
189                    raise TimeoutError('waiting for test output from victim')
190            # read a single character, to avoid blocking
191            # FIXME: there must be a better way to do nonblocking IO!
192            c = fh.read(1)
193            # can see EOF if fh is a telnet socket that was closed in the meantime
194            if c == '':
195                raise EOFError('read from sub-process returned EOF')
196            line += c
197        return line
198
199    def _read_until_block(self, fh):
200        """ Reads from the console until it blocks or 30 sec have passed """
201        start = datetime.datetime.now()
202        while start + AFTER_FINISH_TIMEOUT > datetime.datetime.now():
203            try:
204                timeout = datetime.timedelta(seconds=1) + datetime.datetime.now()
205                yield self._readline(fh, timeout=timeout)
206            except TimeoutError:
207                return
208
209    def collect_data(self, machine):
210        fh = machine.get_output()
211        if fh is None:
212            yield TEST_NO_OUTPUT_LINE
213            return
214        while True:
215            try:
216                line = self._readline(fh)
217            except TimeoutError as e:
218                if self.boot_phase:
219                    if self.boot_attempts < MAX_BOOT_ATTEMPTS:
220                        yield BOOT_TIMEOUT_LINE_RETRY
221                        self.reboot(machine)
222                        continue
223                    else:
224                        yield BOOT_TIMEOUT_LINE_FAIL
225                else:
226                    yield TEST_TIMEOUT_LINE
227                debug.verbose("timeout encountered in collect_data");
228                raise e
229            except EOFError as e:
230                debug.verbose("got EOF from sub-process")
231                break
232
233            yield line
234
235            if not self.boot_phase:
236                self.process_line(line)
237                if self.is_finished(line):
238                    debug.verbose("is_finished returned true for line %s" % line)
239                    # Read remaining lines from console until it blocks
240                    if self.read_after_finished:
241                        for x in self._read_until_block(fh):
242                            self.process_line(x)
243                            yield x
244                    break
245            elif self.is_booted(line):
246                self.boot_phase = False
247                self.set_timeout(self.test_timeout_delta)
248                self.process_line(line)
249
250    def run(self, build, machine, testdir):
251        modules = self.get_modules(build, machine)
252        self.boot(machine, modules)
253        return self.collect_data(machine)
254
255    def cleanup(self, machine):
256        tftp_dir = machine.get_tftp_dir()
257        machine.shutdown()
258        machine.unlock()
259        debug.verbose('removing %s' % tftp_dir)
260        shutil.rmtree(tftp_dir, ignore_errors=True)
261
262
263class InteractiveTest(TestCommon):
264    """
265    A interactive test class that allows a test-case to interact with
266    the fish shell. Sub-classes should implement the interact method.
267
268    As an example, have a look at coreboottest.py.
269    """
270
271    def get_modules(self, build, machine):
272        modules = super(InteractiveTest, self).get_modules(build, machine)
273        # Load the console
274        serialargs = ["auto"]
275        if machine.get_machine_name() == "tomme1" or \
276           machine.get_machine_name() == "tomme2":
277            serialargs = ["portbase=0x2f8", "irq=0x3"]
278
279        modules.add_module(machine.get_serial_binary(), args=serialargs)
280
281        modules.add_module("fish", args=["nospawn"])
282        # use terminal type 'dumb' here to disable linenoise readline stuff
283        modules.add_module("angler", args=['serial0.terminal', 'dumb'])
284        return modules
285
286    def wait_for_prompt(self):
287        self.console.expect(">")
288
289    def wait_for_fish(self):
290        debug.verbose("Waiting for fish.")
291        self.console.expect("fish v0.2 -- pleased to meet you!",
292                timeout=self.test_timeout)
293        self.wait_for_prompt()
294
295    def interact(self):
296        # Implement interaction with console
297        pass
298
299    def set_timeouts(self, machine):
300        self.boot_timeout = machine.get_boot_timeout()
301        if not self.boot_timeout:
302            self.boot_timeout = DEFAULT_BOOT_TIMEOUT.seconds
303        self.test_timeout = machine.get_test_timeout()
304        if not self.test_timeout:
305            self.test_timeout = DEFAULT_TEST_TIMEOUT.seconds
306
307    def collect_data(self, machine):
308        fh = machine.get_output()
309
310
311        self.console = SignalledFdSpawn(fh, timeout=self.test_timeout)
312        self.console.logfile = open(os.path.join(self.testdir, RAW_TEST_OUTPUT_FILENAME), 'wb+')
313
314        while self.boot_attempts < MAX_BOOT_ATTEMPTS:
315            index = self.console.expect(["Barrelfish CPU driver starting",
316                                 pexpect.TIMEOUT, pexpect.EOF],
317                                 timeout=self.boot_timeout)
318            if index == 0:
319                self.boot_phase = False
320                break
321            if index == 1:
322                self.console.logfile.write(BOOT_TIMEOUT_LINE_RETRY)
323                self.reboot(machine)
324            if index == 2:
325                self.console.logfile.write(BOOT_TIMEOUT_LINE_FAIL)
326
327        if not self.boot_phase:
328            machine.force_write(self.console)
329            try:
330                self.interact()
331            except (pexpect.TIMEOUT, OSError), e:
332                self.console.logfile.seek(0)
333                print "Interaction timed out:"
334                print ''.join(self.console.logfile.readlines())
335                raise e
336
337        self.console.logfile.seek(0)
338        return self.console.logfile.readlines()
339
340    def run(self, build, machine, testdir):
341        modules = self.get_modules(build, machine)
342        self.set_timeouts(machine)
343        self.boot(machine, modules)
344        return self.collect_data(machine)
345
346    def process_data(self, testdir, rawiter):
347        """Implement in subclasses to check whether test passed"""
348        raise Exception("Implement process_data in Test %s" % self.name)
349        pass
350
351
352# utility function used by other tests
353def select_timeout(timeout, rlist=[], wlist=[], xlist=[]):
354    """run select.select, with a timeout specified as a datetime object"""
355    delta = timeout - datetime.datetime.now()
356    if delta.days >= 0:
357        assert(delta.days == 0) # unimplemented, and insane!
358        secs = delta.seconds + delta.microseconds / 1000000.0
359        assert(secs > 0)
360        return select.select(rlist, wlist, xlist, secs)
361    else: # already timed out
362        return ([], [], [])
363