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=360)
18DEFAULT_BOOT_TIMEOUT = datetime.timedelta(seconds=240)
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.startswith("Aborted")
157
158    def is_booted(self, line):
159        # early boot output from Barrelfish kernel
160        return "Barrelfish CPU driver starting" in line
161
162    def process_line(self, rawline):
163        """Can be used by subclasses to hook into the raw output stream."""
164        pass
165
166    def _readline(self, fh, timeout=None):
167        """ if given, timeout parameter overrides self.timeout for call """
168        if timeout is None:
169            timeout = self.timeout
170
171        # standard blocking readline if no timeout is set
172        if not timeout:
173            return fh.readline()
174
175        line = ''
176        fhArray = [fh]
177        while not line.endswith('\n'):
178            # wait until there is something to read, with a timeout
179            (readlist, _, _) = select_timeout(timeout, fhArray)
180            if not readlist:
181                # if we have some partial data, return that first!
182                # we'll be called again, and the next time can raise the error
183                if line:
184                    return line
185                elif self.boot_phase:
186                    raise TimeoutError('waiting for victim to boot')
187                else:
188                    raise TimeoutError('waiting for test output from victim')
189            # read a single character, to avoid blocking
190            # FIXME: there must be a better way to do nonblocking IO!
191            c = fh.read(1)
192            # can see EOF if fh is a telnet socket that was closed in the meantime
193            if c == '':
194                raise EOFError('read from sub-process returned EOF')
195            line += c
196        return line
197
198    def _read_until_block(self, fh):
199        """ Reads from the console until it blocks or 30 sec have passed """
200        start = datetime.datetime.now()
201        while start + AFTER_FINISH_TIMEOUT > datetime.datetime.now():
202            try:
203                timeout = datetime.timedelta(seconds=1) + datetime.datetime.now()
204                yield self._readline(fh, timeout=timeout)
205            except TimeoutError:
206                return
207
208    def collect_data(self, machine):
209        fh = machine.get_output()
210        if fh is None:
211            yield TEST_NO_OUTPUT_LINE
212            return
213        while True:
214            try:
215                line = self._readline(fh)
216            except TimeoutError as e:
217                if self.boot_phase:
218                    if self.boot_attempts < MAX_BOOT_ATTEMPTS:
219                        yield BOOT_TIMEOUT_LINE_RETRY
220                        self.reboot(machine)
221                        continue
222                    else:
223                        yield BOOT_TIMEOUT_LINE_FAIL
224                else:
225                    yield TEST_TIMEOUT_LINE
226                debug.verbose("timeout encountered in collect_data");
227                raise e
228            except EOFError as e:
229                debug.verbose("got EOF from sub-process")
230                break
231
232            yield line
233
234            if not self.boot_phase:
235                self.process_line(line)
236                if self.is_finished(line):
237                    debug.verbose("is_finished returned true for line %s" % line)
238                    # Read remaining lines from console until it blocks
239                    if self.read_after_finished:
240                        for x in self._read_until_block(fh):
241                            self.process_line(x)
242                            yield x
243                    break
244            elif self.is_booted(line):
245                self.boot_phase = False
246                self.set_timeout(self.test_timeout_delta)
247                self.process_line(line)
248
249    def run(self, build, machine, testdir):
250        modules = self.get_modules(build, machine)
251        self.boot(machine, modules)
252        return self.collect_data(machine)
253
254    def cleanup(self, machine):
255        tftp_dir = machine.get_tftp_dir()
256        machine.shutdown()
257        machine.unlock()
258        debug.verbose('removing %s' % tftp_dir)
259        shutil.rmtree(tftp_dir, ignore_errors=True)
260
261
262class InteractiveTest(TestCommon):
263    """
264    A interactive test class that allows a test-case to interact with
265    the fish shell. Sub-classes should implement the interact method.
266
267    As an example, have a look at coreboottest.py.
268    """
269
270    def get_modules(self, build, machine):
271        modules = super(InteractiveTest, self).get_modules(build, machine)
272        # Load the console
273        serialargs = ["auto"]
274        if machine.get_machine_name() == "tomme1" or \
275           machine.get_machine_name() == "tomme2":
276            serialargs = ["portbase=0x2f8", "irq=0x3"]
277
278        modules.add_module(machine.get_serial_binary(), args=serialargs)
279
280        modules.add_module("fish", args=["nospawn"])
281        # use terminal type 'dumb' here to disable linenoise readline stuff
282        modules.add_module("angler", args=['serial0.terminal', 'dumb'])
283        return modules
284
285    def wait_for_prompt(self):
286        self.console.expect(">")
287
288    def wait_for_fish(self):
289        debug.verbose("Waiting for fish.")
290        self.console.expect("fish v0.2 -- pleased to meet you!",
291                timeout=self.test_timeout)
292        self.wait_for_prompt()
293
294    def interact(self):
295        # Implement interaction with console
296        pass
297
298    def set_timeouts(self, machine):
299        self.boot_timeout = machine.get_boot_timeout()
300        if not self.boot_timeout:
301            self.boot_timeout = DEFAULT_BOOT_TIMEOUT.seconds
302        self.test_timeout = machine.get_test_timeout()
303        if not self.test_timeout:
304            self.test_timeout = DEFAULT_TEST_TIMEOUT.seconds
305
306    def collect_data(self, machine):
307        fh = machine.get_output()
308
309
310        self.console = SignalledFdSpawn(fh, timeout=self.test_timeout)
311        self.console.logfile = open(os.path.join(self.testdir, RAW_TEST_OUTPUT_FILENAME), 'wb+')
312
313        while self.boot_attempts < MAX_BOOT_ATTEMPTS:
314            index = self.console.expect(["Barrelfish CPU driver starting",
315                                 pexpect.TIMEOUT, pexpect.EOF],
316                                 timeout=self.boot_timeout)
317            if index == 0:
318                self.boot_phase = False
319                break
320            if index == 1:
321                self.console.logfile.write(BOOT_TIMEOUT_LINE_RETRY)
322                self.reboot(machine)
323            if index == 2:
324                self.console.logfile.write(BOOT_TIMEOUT_LINE_FAIL)
325
326        if not self.boot_phase:
327            machine.force_write(self.console)
328            try:
329                self.interact()
330            except (pexpect.TIMEOUT, OSError), e:
331                self.console.logfile.seek(0)
332                print "Interaction timed out:"
333                print ''.join(self.console.logfile.readlines())
334                raise e
335
336        self.console.logfile.seek(0)
337        return self.console.logfile.readlines()
338
339    def run(self, build, machine, testdir):
340        modules = self.get_modules(build, machine)
341        self.set_timeouts(machine)
342        self.boot(machine, modules)
343        return self.collect_data(machine)
344
345    def process_data(self, testdir, rawiter):
346        """Implement in subclasses to check whether test passed"""
347        raise Exception("Implement process_data in Test %s" % self.name)
348        pass
349
350
351# utility function used by other tests
352def select_timeout(timeout, rlist=[], wlist=[], xlist=[]):
353    """run select.select, with a timeout specified as a datetime object"""
354    delta = timeout - datetime.datetime.now()
355    if delta.days >= 0:
356        assert(delta.days == 0) # unimplemented, and insane!
357        secs = delta.seconds + delta.microseconds / 1000000.0
358        assert(secs > 0)
359        return select.select(rlist, wlist, xlist, secs)
360    else: # already timed out
361        return ([], [], [])
362