1c342db35SBrad Bishop#
2eb8dc403SDave Cobbley# Copyright (C) 2013 Intel Corporation
3eb8dc403SDave Cobbley#
4c342db35SBrad Bishop# SPDX-License-Identifier: MIT
5c342db35SBrad Bishop#
6eb8dc403SDave Cobbley
7eb8dc403SDave Cobbley# This module provides a class for starting qemu images using runqemu.
8eb8dc403SDave Cobbley# It's used by testimage.bbclass.
9eb8dc403SDave Cobbley
10eb8dc403SDave Cobbleyimport subprocess
11eb8dc403SDave Cobbleyimport os
12eb8dc403SDave Cobbleyimport sys
13eb8dc403SDave Cobbleyimport time
14eb8dc403SDave Cobbleyimport signal
15eb8dc403SDave Cobbleyimport re
16eb8dc403SDave Cobbleyimport socket
17eb8dc403SDave Cobbleyimport select
18eb8dc403SDave Cobbleyimport errno
19eb8dc403SDave Cobbleyimport string
20eb8dc403SDave Cobbleyimport threading
21eb8dc403SDave Cobbleyimport codecs
22eb8dc403SDave Cobbleyimport logging
23c926e17cSAndrew Geisslerimport tempfile
24eb8dc403SDave Cobbleyfrom oeqa.utils.dump import HostDumper
2582c905dcSAndrew Geisslerfrom collections import defaultdict
26c926e17cSAndrew Geisslerimport importlib
27eb8dc403SDave Cobbley
28eb8dc403SDave Cobbley# Get Unicode non printable control chars
29eb8dc403SDave Cobbleycontrol_range = list(range(0,32))+list(range(127,160))
30eb8dc403SDave Cobbleycontrol_chars = [chr(x) for x in control_range
31eb8dc403SDave Cobbley                if chr(x) not in string.printable]
32eb8dc403SDave Cobbleyre_control_char = re.compile('[%s]' % re.escape("".join(control_chars)))
33eb8dc403SDave Cobbley
34eb8dc403SDave Cobbleyclass QemuRunner:
35eb8dc403SDave Cobbley
3619323693SBrad Bishop    def __init__(self, machine, rootfs, display, tmpdir, deploy_dir_image, logfile, boottime, dump_dir, dump_host_cmds,
373b8a17c1SAndrew Geissler                 use_kvm, logger, use_slirp=False, serial_ports=2, boot_patterns = defaultdict(str), use_ovmf=False, workdir=None, tmpfsdir=None):
38eb8dc403SDave Cobbley
39eb8dc403SDave Cobbley        # Popen object for runqemu
40eb8dc403SDave Cobbley        self.runqemu = None
4182c905dcSAndrew Geissler        self.runqemu_exited = False
42eb8dc403SDave Cobbley        # pid of the qemu process that runqemu will start
43eb8dc403SDave Cobbley        self.qemupid = None
44eb8dc403SDave Cobbley        # target ip - from the command line or runqemu output
45eb8dc403SDave Cobbley        self.ip = None
46eb8dc403SDave Cobbley        # host ip - where qemu is running
47eb8dc403SDave Cobbley        self.server_ip = None
48eb8dc403SDave Cobbley        # target ip netmask
49eb8dc403SDave Cobbley        self.netmask = None
50eb8dc403SDave Cobbley
51eb8dc403SDave Cobbley        self.machine = machine
52eb8dc403SDave Cobbley        self.rootfs = rootfs
53eb8dc403SDave Cobbley        self.display = display
54eb8dc403SDave Cobbley        self.tmpdir = tmpdir
55eb8dc403SDave Cobbley        self.deploy_dir_image = deploy_dir_image
56eb8dc403SDave Cobbley        self.logfile = logfile
57eb8dc403SDave Cobbley        self.boottime = boottime
58eb8dc403SDave Cobbley        self.logged = False
59eb8dc403SDave Cobbley        self.thread = None
60eb8dc403SDave Cobbley        self.use_kvm = use_kvm
6182c905dcSAndrew Geissler        self.use_ovmf = use_ovmf
6219323693SBrad Bishop        self.use_slirp = use_slirp
6382c905dcSAndrew Geissler        self.serial_ports = serial_ports
64eb8dc403SDave Cobbley        self.msg = ''
6582c905dcSAndrew Geissler        self.boot_patterns = boot_patterns
663b8a17c1SAndrew Geissler        self.tmpfsdir = tmpfsdir
67eb8dc403SDave Cobbley
680903674eSAndrew Geissler        self.runqemutime = 300
69b7d28619SAndrew Geissler        if not workdir:
70b7d28619SAndrew Geissler            workdir = os.getcwd()
71b7d28619SAndrew Geissler        self.qemu_pidfile = workdir + '/pidfile_' + str(os.getpid())
72eb8dc403SDave Cobbley        self.host_dumper = HostDumper(dump_host_cmds, dump_dir)
7315ae2509SBrad Bishop        self.monitorpipe = None
74eb8dc403SDave Cobbley
75eb8dc403SDave Cobbley        self.logger = logger
76ac69b488SWilliam A. Kennington III        # Whether we're expecting an exit and should show related errors
77ac69b488SWilliam A. Kennington III        self.canexit = False
78eb8dc403SDave Cobbley
7982c905dcSAndrew Geissler        # Enable testing other OS's
8082c905dcSAndrew Geissler        # Set commands for target communication, and default to Linux ALWAYS
8182c905dcSAndrew Geissler        # Other OS's or baremetal applications need to provide their
8282c905dcSAndrew Geissler        # own implementation passing it through QemuRunner's constructor
8382c905dcSAndrew Geissler        # or by passing them through TESTIMAGE_BOOT_PATTERNS[flag]
8482c905dcSAndrew Geissler        # provided variables, where <flag> is one of the mentioned below.
8582c905dcSAndrew Geissler        accepted_patterns = ['search_reached_prompt', 'send_login_user', 'search_login_succeeded', 'search_cmd_finished']
8682c905dcSAndrew Geissler        default_boot_patterns = defaultdict(str)
8782c905dcSAndrew Geissler        # Default to the usual paterns used to communicate with the target
8887f5cff0SAndrew Geissler        default_boot_patterns['search_reached_prompt'] = ' login:'
8982c905dcSAndrew Geissler        default_boot_patterns['send_login_user'] = 'root\n'
9082c905dcSAndrew Geissler        default_boot_patterns['search_login_succeeded'] = r"root@[a-zA-Z0-9\-]+:~#"
9182c905dcSAndrew Geissler        default_boot_patterns['search_cmd_finished'] = r"[a-zA-Z0-9]+@[a-zA-Z0-9\-]+:~#"
9282c905dcSAndrew Geissler
9382c905dcSAndrew Geissler        # Only override patterns that were set e.g. login user TESTIMAGE_BOOT_PATTERNS[send_login_user] = "webserver\n"
9482c905dcSAndrew Geissler        for pattern in accepted_patterns:
9582c905dcSAndrew Geissler            if not self.boot_patterns[pattern]:
9682c905dcSAndrew Geissler                self.boot_patterns[pattern] = default_boot_patterns[pattern]
9782c905dcSAndrew Geissler
98eb8dc403SDave Cobbley    def create_socket(self):
99eb8dc403SDave Cobbley        try:
100eb8dc403SDave Cobbley            sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
101eb8dc403SDave Cobbley            sock.setblocking(0)
102eb8dc403SDave Cobbley            sock.bind(("127.0.0.1",0))
103eb8dc403SDave Cobbley            sock.listen(2)
104eb8dc403SDave Cobbley            port = sock.getsockname()[1]
105eb8dc403SDave Cobbley            self.logger.debug("Created listening socket for qemu serial console on: 127.0.0.1:%s" % port)
106eb8dc403SDave Cobbley            return (sock, port)
107eb8dc403SDave Cobbley
108eb8dc403SDave Cobbley        except socket.error:
109eb8dc403SDave Cobbley            sock.close()
110eb8dc403SDave Cobbley            raise
111eb8dc403SDave Cobbley
11287f5cff0SAndrew Geissler    def decode_qemulog(self, todecode):
11387f5cff0SAndrew Geissler        # Sanitize the data received from qemu as it may contain control characters
11487f5cff0SAndrew Geissler        msg = todecode.decode("utf-8", errors='ignore')
11587f5cff0SAndrew Geissler        msg = re_control_char.sub('', msg)
11687f5cff0SAndrew Geissler        return msg
11787f5cff0SAndrew Geissler
118eb8dc403SDave Cobbley    def log(self, msg):
119eb8dc403SDave Cobbley        if self.logfile:
12087f5cff0SAndrew Geissler            msg = self.decode_qemulog(msg)
121eb8dc403SDave Cobbley            self.msg += msg
122eb8dc403SDave Cobbley            with codecs.open(self.logfile, "a", encoding="utf-8") as f:
123eb8dc403SDave Cobbley                f.write("%s" % msg)
124eb8dc403SDave Cobbley
125eb8dc403SDave Cobbley    def getOutput(self, o):
126eb8dc403SDave Cobbley        import fcntl
127eb8dc403SDave Cobbley        fl = fcntl.fcntl(o, fcntl.F_GETFL)
128eb8dc403SDave Cobbley        fcntl.fcntl(o, fcntl.F_SETFL, fl | os.O_NONBLOCK)
129d159c7fbSAndrew Geissler        try:
130eb8dc403SDave Cobbley            return os.read(o.fileno(), 1000000).decode("utf-8")
131d159c7fbSAndrew Geissler        except BlockingIOError:
132d159c7fbSAndrew Geissler            return ""
133eb8dc403SDave Cobbley
134eb8dc403SDave Cobbley
135eb8dc403SDave Cobbley    def handleSIGCHLD(self, signum, frame):
136eb8dc403SDave Cobbley        if self.runqemu and self.runqemu.poll():
137eb8dc403SDave Cobbley            if self.runqemu.returncode:
13882c905dcSAndrew Geissler                self.logger.error('runqemu exited with code %d' % self.runqemu.returncode)
13982c905dcSAndrew Geissler                self.logger.error('Output from runqemu:\n%s' % self.getOutput(self.runqemu.stdout))
140eb8dc403SDave Cobbley                self.stop()
141eb8dc403SDave Cobbley                self._dump_host()
142eb8dc403SDave Cobbley
143eb8dc403SDave Cobbley    def start(self, qemuparams = None, get_ip = True, extra_bootparams = None, runqemuparams='', launch_cmd=None, discard_writes=True):
144eb8dc403SDave Cobbley        env = os.environ.copy()
145eb8dc403SDave Cobbley        if self.display:
146eb8dc403SDave Cobbley            env["DISPLAY"] = self.display
147eb8dc403SDave Cobbley            # Set this flag so that Qemu doesn't do any grabs as SDL grabs
148eb8dc403SDave Cobbley            # interact badly with screensavers.
149eb8dc403SDave Cobbley            env["QEMU_DONT_GRAB"] = "1"
150eb8dc403SDave Cobbley        if not os.path.exists(self.rootfs):
151eb8dc403SDave Cobbley            self.logger.error("Invalid rootfs %s" % self.rootfs)
152eb8dc403SDave Cobbley            return False
153eb8dc403SDave Cobbley        if not os.path.exists(self.tmpdir):
154eb8dc403SDave Cobbley            self.logger.error("Invalid TMPDIR path %s" % self.tmpdir)
155eb8dc403SDave Cobbley            return False
156eb8dc403SDave Cobbley        else:
157eb8dc403SDave Cobbley            env["OE_TMPDIR"] = self.tmpdir
158eb8dc403SDave Cobbley        if not os.path.exists(self.deploy_dir_image):
159eb8dc403SDave Cobbley            self.logger.error("Invalid DEPLOY_DIR_IMAGE path %s" % self.deploy_dir_image)
160eb8dc403SDave Cobbley            return False
161eb8dc403SDave Cobbley        else:
162eb8dc403SDave Cobbley            env["DEPLOY_DIR_IMAGE"] = self.deploy_dir_image
163eb8dc403SDave Cobbley
1643b8a17c1SAndrew Geissler        if self.tmpfsdir:
1653b8a17c1SAndrew Geissler            env["RUNQEMU_TMPFS_DIR"] = self.tmpfsdir
1663b8a17c1SAndrew Geissler
167eb8dc403SDave Cobbley        if not launch_cmd:
16808902b01SBrad Bishop            launch_cmd = 'runqemu %s' % ('snapshot' if discard_writes else '')
169eb8dc403SDave Cobbley            if self.use_kvm:
170eb8dc403SDave Cobbley                self.logger.debug('Using kvm for runqemu')
171eb8dc403SDave Cobbley                launch_cmd += ' kvm'
172eb8dc403SDave Cobbley            else:
173eb8dc403SDave Cobbley                self.logger.debug('Not using kvm for runqemu')
174eb8dc403SDave Cobbley            if not self.display:
175eb8dc403SDave Cobbley                launch_cmd += ' nographic'
17619323693SBrad Bishop            if self.use_slirp:
17719323693SBrad Bishop                launch_cmd += ' slirp'
17882c905dcSAndrew Geissler            if self.use_ovmf:
17982c905dcSAndrew Geissler                launch_cmd += ' ovmf'
180517393d9SAndrew Geissler            launch_cmd += ' %s %s' % (runqemuparams, self.machine)
181517393d9SAndrew Geissler            if self.rootfs.endswith('.vmdk'):
182517393d9SAndrew Geissler                self.logger.debug('Bypassing VMDK rootfs for runqemu')
183517393d9SAndrew Geissler            else:
184517393d9SAndrew Geissler                launch_cmd += ' %s' % (self.rootfs)
185eb8dc403SDave Cobbley
186eb8dc403SDave Cobbley        return self.launch(launch_cmd, qemuparams=qemuparams, get_ip=get_ip, extra_bootparams=extra_bootparams, env=env)
187eb8dc403SDave Cobbley
188eb8dc403SDave Cobbley    def launch(self, launch_cmd, get_ip = True, qemuparams = None, extra_bootparams = None, env = None):
189c926e17cSAndrew Geissler        # use logfile to determine the recipe-sysroot-native path and
190c926e17cSAndrew Geissler        # then add in the site-packages path components and add that
191c926e17cSAndrew Geissler        # to the python sys.path so qmp.py can be found.
192c926e17cSAndrew Geissler        python_path = os.path.dirname(os.path.dirname(self.logfile))
193eff27476SAndrew Geissler        python_path += "/recipe-sysroot-native/usr/lib/qemu-python"
194c926e17cSAndrew Geissler        sys.path.append(python_path)
195c926e17cSAndrew Geissler        importlib.invalidate_caches()
196c926e17cSAndrew Geissler        try:
197c926e17cSAndrew Geissler            qmp = importlib.import_module("qmp")
19887f5cff0SAndrew Geissler        except Exception as e:
19987f5cff0SAndrew Geissler            self.logger.error("qemurunner: qmp.py missing, please ensure it's installed (%s)" % str(e))
200c926e17cSAndrew Geissler            return False
201c926e17cSAndrew Geissler        # Path relative to tmpdir used as cwd for qemu below to avoid unix socket path length issues
202c926e17cSAndrew Geissler        qmp_file = "." + next(tempfile._get_candidate_names())
203c926e17cSAndrew Geissler        qmp_param = ' -S -qmp unix:./%s,server,wait' % (qmp_file)
204c926e17cSAndrew Geissler        qmp_port = self.tmpdir + "/" + qmp_file
2050903674eSAndrew Geissler        # Create a second socket connection for debugging use,
2060903674eSAndrew Geissler        # note this will NOT cause qemu to block waiting for the connection
2070903674eSAndrew Geissler        qmp_file2 = "." + next(tempfile._get_candidate_names())
2080903674eSAndrew Geissler        qmp_param += ' -qmp unix:./%s,server,nowait' % (qmp_file2)
2090903674eSAndrew Geissler        qmp_port2 = self.tmpdir + "/" + qmp_file2
2100903674eSAndrew Geissler        self.logger.info("QMP Available for connection at %s" % (qmp_port2))
211c926e17cSAndrew Geissler
212eb8dc403SDave Cobbley        try:
21382c905dcSAndrew Geissler            if self.serial_ports >= 2:
214f86d0556SBrad Bishop                self.threadsock, threadport = self.create_socket()
215eb8dc403SDave Cobbley            self.server_socket, self.serverport = self.create_socket()
216eb8dc403SDave Cobbley        except socket.error as msg:
217eb8dc403SDave Cobbley            self.logger.error("Failed to create listening socket: %s" % msg[1])
218eb8dc403SDave Cobbley            return False
219eb8dc403SDave Cobbley
22095ac1b8dSAndrew Geissler        bootparams = ' printk.time=1'
221eb8dc403SDave Cobbley        if extra_bootparams:
222eb8dc403SDave Cobbley            bootparams = bootparams + ' ' + extra_bootparams
223eb8dc403SDave Cobbley
224eb8dc403SDave Cobbley        # Ask QEMU to store the QEMU process PID in file, this way we don't have to parse running processes
225eb8dc403SDave Cobbley        # and analyze descendents in order to determine it.
226eb8dc403SDave Cobbley        if os.path.exists(self.qemu_pidfile):
227eb8dc403SDave Cobbley            os.remove(self.qemu_pidfile)
228c926e17cSAndrew Geissler        self.qemuparams = 'bootparams="{0}" qemuparams="-pidfile {1} {2}"'.format(bootparams, self.qemu_pidfile, qmp_param)
229c926e17cSAndrew Geissler
230eb8dc403SDave Cobbley        if qemuparams:
231eb8dc403SDave Cobbley            self.qemuparams = self.qemuparams[:-1] + " " + qemuparams + " " + '\"'
232eb8dc403SDave Cobbley
23382c905dcSAndrew Geissler        if self.serial_ports >= 2:
23415ae2509SBrad Bishop            launch_cmd += ' tcpserial=%s:%s %s' % (threadport, self.serverport, self.qemuparams)
23582c905dcSAndrew Geissler        else:
23682c905dcSAndrew Geissler            launch_cmd += ' tcpserial=%s %s' % (self.serverport, self.qemuparams)
237eb8dc403SDave Cobbley
238eb8dc403SDave Cobbley        self.origchldhandler = signal.getsignal(signal.SIGCHLD)
239eb8dc403SDave Cobbley        signal.signal(signal.SIGCHLD, self.handleSIGCHLD)
240eb8dc403SDave Cobbley
241eb8dc403SDave Cobbley        self.logger.debug('launchcmd=%s'%(launch_cmd))
242eb8dc403SDave Cobbley
243eb8dc403SDave Cobbley        # FIXME: We pass in stdin=subprocess.PIPE here to work around stty
244eb8dc403SDave Cobbley        # blocking at the end of the runqemu script when using this within
245eb8dc403SDave Cobbley        # oe-selftest (this makes stty error out immediately). There ought
246eb8dc403SDave Cobbley        # to be a proper fix but this will suffice for now.
247c926e17cSAndrew Geissler        self.runqemu = subprocess.Popen(launch_cmd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, stdin=subprocess.PIPE, preexec_fn=os.setpgrp, env=env, cwd=self.tmpdir)
248eb8dc403SDave Cobbley        output = self.runqemu.stdout
2495f35090dSAndrew Geissler        launch_time = time.time()
250eb8dc403SDave Cobbley
251eb8dc403SDave Cobbley        #
252eb8dc403SDave Cobbley        # We need the preexec_fn above so that all runqemu processes can easily be killed
253eb8dc403SDave Cobbley        # (by killing their process group). This presents a problem if this controlling
254eb8dc403SDave Cobbley        # process itself is killed however since those processes don't notice the death
255eb8dc403SDave Cobbley        # of the parent and merrily continue on.
256eb8dc403SDave Cobbley        #
257eb8dc403SDave Cobbley        # Rather than hack runqemu to deal with this, we add something here instead.
258eb8dc403SDave Cobbley        # Basically we fork off another process which holds an open pipe to the parent
259eb8dc403SDave Cobbley        # and also is setpgrp. If/when the pipe sees EOF from the parent dieing, it kills
260eb8dc403SDave Cobbley        # the process group. This is like pctrl's PDEATHSIG but for a process group
261eb8dc403SDave Cobbley        # rather than a single process.
262eb8dc403SDave Cobbley        #
263eb8dc403SDave Cobbley        r, w = os.pipe()
264eb8dc403SDave Cobbley        self.monitorpid = os.fork()
265eb8dc403SDave Cobbley        if self.monitorpid:
266eb8dc403SDave Cobbley            os.close(r)
267eb8dc403SDave Cobbley            self.monitorpipe = os.fdopen(w, "w")
268eb8dc403SDave Cobbley        else:
269eb8dc403SDave Cobbley            # child process
270eb8dc403SDave Cobbley            os.setpgrp()
271eb8dc403SDave Cobbley            os.close(w)
272eb8dc403SDave Cobbley            r = os.fdopen(r)
273eb8dc403SDave Cobbley            x = r.read()
274eb8dc403SDave Cobbley            os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
27593c203f3SPatrick Williams            os._exit(0)
276eb8dc403SDave Cobbley
277eb8dc403SDave Cobbley        self.logger.debug("runqemu started, pid is %s" % self.runqemu.pid)
278eb8dc403SDave Cobbley        self.logger.debug("waiting at most %s seconds for qemu pid (%s)" %
279eb8dc403SDave Cobbley                          (self.runqemutime, time.strftime("%D %H:%M:%S")))
280eb8dc403SDave Cobbley        endtime = time.time() + self.runqemutime
281eb8dc403SDave Cobbley        while not self.is_alive() and time.time() < endtime:
282eb8dc403SDave Cobbley            if self.runqemu.poll():
28382c905dcSAndrew Geissler                if self.runqemu_exited:
284c926e17cSAndrew Geissler                    self.logger.warning("runqemu during is_alive() test")
28582c905dcSAndrew Geissler                    return False
286eb8dc403SDave Cobbley                if self.runqemu.returncode:
287eb8dc403SDave Cobbley                    # No point waiting any longer
28896ff1984SBrad Bishop                    self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
289eb8dc403SDave Cobbley                    self._dump_host()
29096ff1984SBrad Bishop                    self.logger.warning("Output from runqemu:\n%s" % self.getOutput(output))
291f86d0556SBrad Bishop                    self.stop()
292eb8dc403SDave Cobbley                    return False
293eb8dc403SDave Cobbley            time.sleep(0.5)
294eb8dc403SDave Cobbley
29582c905dcSAndrew Geissler        if self.runqemu_exited:
296c926e17cSAndrew Geissler            self.logger.warning("runqemu after timeout")
29782c905dcSAndrew Geissler
298c926e17cSAndrew Geissler        if self.runqemu.returncode:
299c926e17cSAndrew Geissler            self.logger.warning('runqemu exited with code %d' % self.runqemu.returncode)
300c926e17cSAndrew Geissler
301c926e17cSAndrew Geissler        if not self.is_alive():
302ac69b488SWilliam A. Kennington III            self.logger.error("Qemu pid didn't appear in %s seconds (%s)" %
303ac69b488SWilliam A. Kennington III                              (self.runqemutime, time.strftime("%D %H:%M:%S")))
304ac69b488SWilliam A. Kennington III
305ac69b488SWilliam A. Kennington III            qemu_pid = None
306ac69b488SWilliam A. Kennington III            if os.path.isfile(self.qemu_pidfile):
307ac69b488SWilliam A. Kennington III                with open(self.qemu_pidfile, 'r') as f:
308ac69b488SWilliam A. Kennington III                    qemu_pid = f.read().strip()
309ac69b488SWilliam A. Kennington III
310ac69b488SWilliam A. Kennington III            self.logger.error("Status information, poll status: %s, pidfile exists: %s, pidfile contents %s, proc pid exists %s"
311ac69b488SWilliam A. Kennington III                % (self.runqemu.poll(), os.path.isfile(self.qemu_pidfile), str(qemu_pid), os.path.exists("/proc/" + str(qemu_pid))))
312ac69b488SWilliam A. Kennington III
313ac69b488SWilliam A. Kennington III            # Dump all processes to help us to figure out what is going on...
314ac69b488SWilliam A. Kennington III            ps = subprocess.Popen(['ps', 'axww', '-o', 'pid,ppid,pri,ni,command '], stdout=subprocess.PIPE).communicate()[0]
315ac69b488SWilliam A. Kennington III            processes = ps.decode("utf-8")
316ac69b488SWilliam A. Kennington III            self.logger.debug("Running processes:\n%s" % processes)
317ac69b488SWilliam A. Kennington III            self._dump_host()
318ac69b488SWilliam A. Kennington III            op = self.getOutput(output)
319ac69b488SWilliam A. Kennington III            self.stop()
320ac69b488SWilliam A. Kennington III            if op:
321ac69b488SWilliam A. Kennington III                self.logger.error("Output from runqemu:\n%s" % op)
322ac69b488SWilliam A. Kennington III            else:
323ac69b488SWilliam A. Kennington III                self.logger.error("No output from runqemu.\n")
324c926e17cSAndrew Geissler            return False
325c926e17cSAndrew Geissler
326c926e17cSAndrew Geissler        # Create the client socket for the QEMU Monitor Control Socket
327c926e17cSAndrew Geissler        # This will allow us to read status from Qemu if the the process
328c926e17cSAndrew Geissler        # is still alive
329c926e17cSAndrew Geissler        self.logger.debug("QMP Initializing to %s" % (qmp_port))
330c926e17cSAndrew Geissler        # chdir dance for path length issues with unix sockets
331c926e17cSAndrew Geissler        origpath = os.getcwd()
332c926e17cSAndrew Geissler        try:
333c926e17cSAndrew Geissler            os.chdir(os.path.dirname(qmp_port))
334c926e17cSAndrew Geissler            try:
33587f5cff0SAndrew Geissler               from qmp.legacy import QEMUMonitorProtocol
33687f5cff0SAndrew Geissler               self.qmp = QEMUMonitorProtocol(os.path.basename(qmp_port))
337c926e17cSAndrew Geissler            except OSError as msg:
338c926e17cSAndrew Geissler                self.logger.warning("Failed to initialize qemu monitor socket: %s File: %s" % (msg, msg.filename))
339c926e17cSAndrew Geissler                return False
340c926e17cSAndrew Geissler
341c926e17cSAndrew Geissler            self.logger.debug("QMP Connecting to %s" % (qmp_port))
342c926e17cSAndrew Geissler            if not os.path.exists(qmp_port) and self.is_alive():
343c926e17cSAndrew Geissler                self.logger.debug("QMP Port does not exist waiting for it to be created")
344c926e17cSAndrew Geissler                endtime = time.time() + self.runqemutime
345c926e17cSAndrew Geissler                while not os.path.exists(qmp_port) and self.is_alive() and time.time() < endtime:
346c926e17cSAndrew Geissler                   self.logger.info("QMP port does not exist yet!")
347c926e17cSAndrew Geissler                   time.sleep(0.5)
348c926e17cSAndrew Geissler                if not os.path.exists(qmp_port) and self.is_alive():
349c926e17cSAndrew Geissler                    self.logger.warning("QMP Port still does not exist but QEMU is alive")
350c926e17cSAndrew Geissler                    return False
351c926e17cSAndrew Geissler
352c926e17cSAndrew Geissler            try:
353*6aa7eec5SAndrew Geissler                # set timeout value for all QMP calls
354*6aa7eec5SAndrew Geissler                self.qmp.settimeout(self.runqemutime)
355c926e17cSAndrew Geissler                self.qmp.connect()
3565f35090dSAndrew Geissler                connect_time = time.time()
3575f35090dSAndrew Geissler                self.logger.info("QMP connected to QEMU at %s and took %s seconds" %
3585f35090dSAndrew Geissler                                  (time.strftime("%D %H:%M:%S"),
3595f35090dSAndrew Geissler                                   time.time() - launch_time))
360c926e17cSAndrew Geissler            except OSError as msg:
361c926e17cSAndrew Geissler                self.logger.warning("Failed to connect qemu monitor socket: %s File: %s" % (msg, msg.filename))
362c926e17cSAndrew Geissler                return False
3637784c429SPatrick Williams            except qmp.legacy.QMPError as msg:
364c926e17cSAndrew Geissler                self.logger.warning("Failed to communicate with qemu monitor: %s" % (msg))
365c926e17cSAndrew Geissler                return False
366c926e17cSAndrew Geissler        finally:
367c926e17cSAndrew Geissler            os.chdir(origpath)
368c926e17cSAndrew Geissler
3690903674eSAndrew Geissler        # We worry that mmap'd libraries may cause page faults which hang the qemu VM for periods
3700903674eSAndrew Geissler        # causing failures. Before we "start" qemu, read through it's mapped files to try and
3710903674eSAndrew Geissler        # ensure we don't hit page faults later
3720903674eSAndrew Geissler        mapdir = "/proc/" + str(self.qemupid) + "/map_files/"
3730903674eSAndrew Geissler        try:
3740903674eSAndrew Geissler            for f in os.listdir(mapdir):
3755f35090dSAndrew Geissler                try:
3760903674eSAndrew Geissler                    linktarget = os.readlink(os.path.join(mapdir, f))
3770903674eSAndrew Geissler                    if not linktarget.startswith("/") or linktarget.startswith("/dev") or "deleted" in linktarget:
3780903674eSAndrew Geissler                        continue
3790903674eSAndrew Geissler                    with open(linktarget, "rb") as readf:
3800903674eSAndrew Geissler                        data = True
3810903674eSAndrew Geissler                        while data:
3820903674eSAndrew Geissler                            data = readf.read(4096)
3835f35090dSAndrew Geissler                except FileNotFoundError:
3845f35090dSAndrew Geissler                    continue
3850903674eSAndrew Geissler        # Centos7 doesn't allow us to read /map_files/
3860903674eSAndrew Geissler        except PermissionError:
3870903674eSAndrew Geissler            pass
3880903674eSAndrew Geissler
3890903674eSAndrew Geissler        # Release the qemu process to continue running
390c926e17cSAndrew Geissler        self.run_monitor('cont')
3915f35090dSAndrew Geissler        self.logger.info("QMP released QEMU at %s and took %s seconds from connect" %
3925f35090dSAndrew Geissler                          (time.strftime("%D %H:%M:%S"),
3935f35090dSAndrew Geissler                           time.time() - connect_time))
394c926e17cSAndrew Geissler
395eb8dc403SDave Cobbley        # We are alive: qemu is running
396eb8dc403SDave Cobbley        out = self.getOutput(output)
397eb8dc403SDave Cobbley        netconf = False # network configuration is not required by default
398eb8dc403SDave Cobbley        self.logger.debug("qemu started in %s seconds - qemu procces pid is %s (%s)" %
399eb8dc403SDave Cobbley                          (time.time() - (endtime - self.runqemutime),
400eb8dc403SDave Cobbley                           self.qemupid, time.strftime("%D %H:%M:%S")))
401eb8dc403SDave Cobbley        cmdline = ''
40282c905dcSAndrew Geissler        if get_ip:
403eb8dc403SDave Cobbley            with open('/proc/%s/cmdline' % self.qemupid) as p:
404eb8dc403SDave Cobbley                cmdline = p.read()
405eb8dc403SDave Cobbley                # It is needed to sanitize the data received
406eb8dc403SDave Cobbley                # because is possible to have control characters
407eb8dc403SDave Cobbley                cmdline = re_control_char.sub(' ', cmdline)
408eb8dc403SDave Cobbley            try:
40919323693SBrad Bishop                if self.use_slirp:
410517393d9SAndrew Geissler                    tcp_ports = cmdline.split("hostfwd=tcp:")[1]
411517393d9SAndrew Geissler                    ip, tcp_ports = tcp_ports.split(":")[:2]
41219323693SBrad Bishop                    host_port = tcp_ports[:tcp_ports.find('-')]
413517393d9SAndrew Geissler                    self.ip = "%s:%s" % (ip, host_port)
41419323693SBrad Bishop                else:
415f86d0556SBrad Bishop                    ips = re.findall(r"((?:[0-9]{1,3}\.){3}[0-9]{1,3})", cmdline.split("ip=")[1])
416eb8dc403SDave Cobbley                    self.ip = ips[0]
417eb8dc403SDave Cobbley                    self.server_ip = ips[1]
418eb8dc403SDave Cobbley                self.logger.debug("qemu cmdline used:\n{}".format(cmdline))
419eb8dc403SDave Cobbley            except (IndexError, ValueError):
420eb8dc403SDave Cobbley                # Try to get network configuration from runqemu output
421595f6308SAndrew Geissler                match = re.match(r'.*Network configuration: (?:ip=)*([0-9.]+)::([0-9.]+):([0-9.]+).*',
422eb8dc403SDave Cobbley                                 out, re.MULTILINE|re.DOTALL)
423eb8dc403SDave Cobbley                if match:
424eb8dc403SDave Cobbley                    self.ip, self.server_ip, self.netmask = match.groups()
425eb8dc403SDave Cobbley                    # network configuration is required as we couldn't get it
426eb8dc403SDave Cobbley                    # from the runqemu command line, so qemu doesn't run kernel
427eb8dc403SDave Cobbley                    # and guest networking is not configured
428eb8dc403SDave Cobbley                    netconf = True
429eb8dc403SDave Cobbley                else:
430eb8dc403SDave Cobbley                    self.logger.error("Couldn't get ip from qemu command line and runqemu output! "
431eb8dc403SDave Cobbley                                 "Here is the qemu command line used:\n%s\n"
432eb8dc403SDave Cobbley                                 "and output from runqemu:\n%s" % (cmdline, out))
433eb8dc403SDave Cobbley                    self._dump_host()
434eb8dc403SDave Cobbley                    self.stop()
435eb8dc403SDave Cobbley                    return False
436eb8dc403SDave Cobbley
437eb8dc403SDave Cobbley        self.logger.debug("Target IP: %s" % self.ip)
438eb8dc403SDave Cobbley        self.logger.debug("Server IP: %s" % self.server_ip)
439eb8dc403SDave Cobbley
44082c905dcSAndrew Geissler        if self.serial_ports >= 2:
441f86d0556SBrad Bishop            self.thread = LoggingThread(self.log, self.threadsock, self.logger)
442eb8dc403SDave Cobbley            self.thread.start()
443eb8dc403SDave Cobbley            if not self.thread.connection_established.wait(self.boottime):
444eb8dc403SDave Cobbley                self.logger.error("Didn't receive a console connection from qemu. "
445eb8dc403SDave Cobbley                             "Here is the qemu command line used:\n%s\nand "
446eb8dc403SDave Cobbley                             "output from runqemu:\n%s" % (cmdline, out))
447eb8dc403SDave Cobbley                self.stop_thread()
448eb8dc403SDave Cobbley                return False
449eb8dc403SDave Cobbley
450eb8dc403SDave Cobbley        self.logger.debug("Output from runqemu:\n%s", out)
451eb8dc403SDave Cobbley        self.logger.debug("Waiting at most %d seconds for login banner (%s)" %
452eb8dc403SDave Cobbley                          (self.boottime, time.strftime("%D %H:%M:%S")))
453eb8dc403SDave Cobbley        endtime = time.time() + self.boottime
454eb8dc403SDave Cobbley        socklist = [self.server_socket]
455eb8dc403SDave Cobbley        reachedlogin = False
456eb8dc403SDave Cobbley        stopread = False
457eb8dc403SDave Cobbley        qemusock = None
458eb8dc403SDave Cobbley        bootlog = b''
459eb8dc403SDave Cobbley        data = b''
460eb8dc403SDave Cobbley        while time.time() < endtime and not stopread:
461eb8dc403SDave Cobbley            try:
462eb8dc403SDave Cobbley                sread, swrite, serror = select.select(socklist, [], [], 5)
463eb8dc403SDave Cobbley            except InterruptedError:
464eb8dc403SDave Cobbley                continue
465eb8dc403SDave Cobbley            for sock in sread:
466eb8dc403SDave Cobbley                if sock is self.server_socket:
467eb8dc403SDave Cobbley                    qemusock, addr = self.server_socket.accept()
468eb8dc403SDave Cobbley                    qemusock.setblocking(0)
469eb8dc403SDave Cobbley                    socklist.append(qemusock)
470eb8dc403SDave Cobbley                    socklist.remove(self.server_socket)
471eb8dc403SDave Cobbley                    self.logger.debug("Connection from %s:%s" % addr)
472eb8dc403SDave Cobbley                else:
473*6aa7eec5SAndrew Geissler                    # try to avoid reading only a single character at a time
474*6aa7eec5SAndrew Geissler                    time.sleep(0.1)
475eb8dc403SDave Cobbley                    data = data + sock.recv(1024)
476eb8dc403SDave Cobbley                    if data:
477eb8dc403SDave Cobbley                        bootlog += data
47882c905dcSAndrew Geissler                        if self.serial_ports < 2:
47982c905dcSAndrew Geissler                            # this socket has mixed console/kernel data, log it to logfile
48082c905dcSAndrew Geissler                            self.log(data)
48182c905dcSAndrew Geissler
482eb8dc403SDave Cobbley                        data = b''
48387f5cff0SAndrew Geissler
48487f5cff0SAndrew Geissler                        decodedlog = self.decode_qemulog(bootlog)
48587f5cff0SAndrew Geissler                        if self.boot_patterns['search_reached_prompt'] in decodedlog:
486eb8dc403SDave Cobbley                            self.server_socket = qemusock
487eb8dc403SDave Cobbley                            stopread = True
488eb8dc403SDave Cobbley                            reachedlogin = True
48987f5cff0SAndrew Geissler                            self.logger.debug("Reached login banner in %s seconds (%s, %s)" %
490eb8dc403SDave Cobbley                                              (time.time() - (endtime - self.boottime),
49187f5cff0SAndrew Geissler                                              time.strftime("%D %H:%M:%S"), time.time()))
492eb8dc403SDave Cobbley                    else:
493eb8dc403SDave Cobbley                        # no need to check if reachedlogin unless we support multiple connections
494eb8dc403SDave Cobbley                        self.logger.debug("QEMU socket disconnected before login banner reached. (%s)" %
495eb8dc403SDave Cobbley                                          time.strftime("%D %H:%M:%S"))
496eb8dc403SDave Cobbley                        socklist.remove(sock)
497eb8dc403SDave Cobbley                        sock.close()
498eb8dc403SDave Cobbley                        stopread = True
499eb8dc403SDave Cobbley
500eb8dc403SDave Cobbley        if not reachedlogin:
501eb8dc403SDave Cobbley            if time.time() >= endtime:
50296ff1984SBrad Bishop                self.logger.warning("Target didn't reach login banner in %d seconds (%s)" %
503eb8dc403SDave Cobbley                                  (self.boottime, time.strftime("%D %H:%M:%S")))
504eb8dc403SDave Cobbley            tail = lambda l: "\n".join(l.splitlines()[-25:])
50587f5cff0SAndrew Geissler            bootlog = self.decode_qemulog(bootlog)
506eb8dc403SDave Cobbley            # in case bootlog is empty, use tail qemu log store at self.msg
507eb8dc403SDave Cobbley            lines = tail(bootlog if bootlog else self.msg)
50887f5cff0SAndrew Geissler            self.logger.warning("Last 25 lines of text (%d):\n%s" % (len(bootlog), lines))
50996ff1984SBrad Bishop            self.logger.warning("Check full boot log: %s" % self.logfile)
510eb8dc403SDave Cobbley            self._dump_host()
511eb8dc403SDave Cobbley            self.stop()
512eb8dc403SDave Cobbley            return False
513eb8dc403SDave Cobbley
514eb8dc403SDave Cobbley        # If we are not able to login the tests can continue
515eb8dc403SDave Cobbley        try:
516c3d88e4dSAndrew Geissler            (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120)
51782c905dcSAndrew Geissler            if re.search(self.boot_patterns['search_login_succeeded'], output):
518eb8dc403SDave Cobbley                self.logged = True
519eb8dc403SDave Cobbley                self.logger.debug("Logged as root in serial console")
520eb8dc403SDave Cobbley                if netconf:
521eb8dc403SDave Cobbley                    # configure guest networking
522eb8dc403SDave Cobbley                    cmd = "ifconfig eth0 %s netmask %s up\n" % (self.ip, self.netmask)
523eb8dc403SDave Cobbley                    output = self.run_serial(cmd, raw=True)[1]
524f86d0556SBrad Bishop                    if re.search(r"root@[a-zA-Z0-9\-]+:~#", output):
525eb8dc403SDave Cobbley                        self.logger.debug("configured ip address %s", self.ip)
526eb8dc403SDave Cobbley                    else:
527eb8dc403SDave Cobbley                        self.logger.debug("Couldn't configure guest networking")
528eb8dc403SDave Cobbley            else:
52996ff1984SBrad Bishop                self.logger.warning("Couldn't login into serial console"
530eb8dc403SDave Cobbley                            " as root using blank password")
53196ff1984SBrad Bishop                self.logger.warning("The output:\n%s" % output)
532eb8dc403SDave Cobbley        except:
53396ff1984SBrad Bishop            self.logger.warning("Serial console failed while trying to login")
534eb8dc403SDave Cobbley        return True
535eb8dc403SDave Cobbley
536eb8dc403SDave Cobbley    def stop(self):
537eb8dc403SDave Cobbley        if hasattr(self, "origchldhandler"):
538eb8dc403SDave Cobbley            signal.signal(signal.SIGCHLD, self.origchldhandler)
5391a4b7ee2SBrad Bishop        self.stop_thread()
5401a4b7ee2SBrad Bishop        self.stop_qemu_system()
541eb8dc403SDave Cobbley        if self.runqemu:
542eb8dc403SDave Cobbley            if hasattr(self, "monitorpid"):
543eb8dc403SDave Cobbley                os.kill(self.monitorpid, signal.SIGKILL)
544eb8dc403SDave Cobbley                self.logger.debug("Sending SIGTERM to runqemu")
545eb8dc403SDave Cobbley                try:
546eb8dc403SDave Cobbley                    os.killpg(os.getpgid(self.runqemu.pid), signal.SIGTERM)
547eb8dc403SDave Cobbley                except OSError as e:
548eb8dc403SDave Cobbley                    if e.errno != errno.ESRCH:
549eb8dc403SDave Cobbley                        raise
550864cc43bSPatrick Williams            try:
551864cc43bSPatrick Williams                outs, errs = self.runqemu.communicate(timeout = self.runqemutime)
552864cc43bSPatrick Williams                if outs:
553864cc43bSPatrick Williams                    self.logger.info("Output from runqemu:\n%s", outs.decode("utf-8"))
554864cc43bSPatrick Williams                if errs:
555864cc43bSPatrick Williams                    self.logger.info("Stderr from runqemu:\n%s", errs.decode("utf-8"))
556864cc43bSPatrick Williams            except TimeoutExpired:
557eb8dc403SDave Cobbley                self.logger.debug("Sending SIGKILL to runqemu")
558eb8dc403SDave Cobbley                os.killpg(os.getpgid(self.runqemu.pid), signal.SIGKILL)
559d159c7fbSAndrew Geissler            if not self.runqemu.stdout.closed:
560d159c7fbSAndrew Geissler                self.logger.info("Output from runqemu:\n%s" % self.getOutput(self.runqemu.stdout))
561f86d0556SBrad Bishop            self.runqemu.stdin.close()
562f86d0556SBrad Bishop            self.runqemu.stdout.close()
56382c905dcSAndrew Geissler            self.runqemu_exited = True
564f86d0556SBrad Bishop
565c926e17cSAndrew Geissler        if hasattr(self, 'qmp') and self.qmp:
566c926e17cSAndrew Geissler            self.qmp.close()
567c926e17cSAndrew Geissler            self.qmp = None
568eb8dc403SDave Cobbley        if hasattr(self, 'server_socket') and self.server_socket:
569eb8dc403SDave Cobbley            self.server_socket.close()
570eb8dc403SDave Cobbley            self.server_socket = None
571f86d0556SBrad Bishop        if hasattr(self, 'threadsock') and self.threadsock:
572f86d0556SBrad Bishop            self.threadsock.close()
573f86d0556SBrad Bishop            self.threadsock = None
574eb8dc403SDave Cobbley        self.qemupid = None
575eb8dc403SDave Cobbley        self.ip = None
576eb8dc403SDave Cobbley        if os.path.exists(self.qemu_pidfile):
57782c905dcSAndrew Geissler            try:
578eb8dc403SDave Cobbley                os.remove(self.qemu_pidfile)
57982c905dcSAndrew Geissler            except FileNotFoundError as e:
58082c905dcSAndrew Geissler                # We raced, ignore
58182c905dcSAndrew Geissler                pass
582f86d0556SBrad Bishop        if self.monitorpipe:
583f86d0556SBrad Bishop            self.monitorpipe.close()
584eb8dc403SDave Cobbley
585eb8dc403SDave Cobbley    def stop_qemu_system(self):
586eb8dc403SDave Cobbley        if self.qemupid:
587eb8dc403SDave Cobbley            try:
588eb8dc403SDave Cobbley                # qemu-system behaves well and a SIGTERM is enough
589eb8dc403SDave Cobbley                os.kill(self.qemupid, signal.SIGTERM)
590eb8dc403SDave Cobbley            except ProcessLookupError as e:
5911a4b7ee2SBrad Bishop                self.logger.warning('qemu-system ended unexpectedly')
592eb8dc403SDave Cobbley
593eb8dc403SDave Cobbley    def stop_thread(self):
594eb8dc403SDave Cobbley        if self.thread and self.thread.is_alive():
595eb8dc403SDave Cobbley            self.thread.stop()
596eb8dc403SDave Cobbley            self.thread.join()
597eb8dc403SDave Cobbley
598c926e17cSAndrew Geissler    def allowexit(self):
599ac69b488SWilliam A. Kennington III        self.canexit = True
600c926e17cSAndrew Geissler        if self.thread:
601c926e17cSAndrew Geissler            self.thread.allowexit()
602c926e17cSAndrew Geissler
603eb8dc403SDave Cobbley    def restart(self, qemuparams = None):
60496ff1984SBrad Bishop        self.logger.warning("Restarting qemu process")
605eb8dc403SDave Cobbley        if self.runqemu.poll() is None:
606eb8dc403SDave Cobbley            self.stop()
607eb8dc403SDave Cobbley        if self.start(qemuparams):
608eb8dc403SDave Cobbley            return True
609eb8dc403SDave Cobbley        return False
610eb8dc403SDave Cobbley
611eb8dc403SDave Cobbley    def is_alive(self):
61282c905dcSAndrew Geissler        if not self.runqemu or self.runqemu.poll() is not None or self.runqemu_exited:
613eb8dc403SDave Cobbley            return False
614eb8dc403SDave Cobbley        if os.path.isfile(self.qemu_pidfile):
61596ff1984SBrad Bishop            # when handling pidfile, qemu creates the file, stat it, lock it and then write to it
61696ff1984SBrad Bishop            # so it's possible that the file has been created but the content is empty
61796ff1984SBrad Bishop            pidfile_timeout = time.time() + 3
61896ff1984SBrad Bishop            while time.time() < pidfile_timeout:
61996ff1984SBrad Bishop                with open(self.qemu_pidfile, 'r') as f:
62096ff1984SBrad Bishop                    qemu_pid = f.read().strip()
62196ff1984SBrad Bishop                # file created but not yet written contents
62296ff1984SBrad Bishop                if not qemu_pid:
62396ff1984SBrad Bishop                    time.sleep(0.5)
62496ff1984SBrad Bishop                    continue
62596ff1984SBrad Bishop                else:
62696ff1984SBrad Bishop                    if os.path.exists("/proc/" + qemu_pid):
62796ff1984SBrad Bishop                        self.qemupid = int(qemu_pid)
628eb8dc403SDave Cobbley                        return True
629eb8dc403SDave Cobbley        return False
630eb8dc403SDave Cobbley
6315f35090dSAndrew Geissler    def run_monitor(self, command, args=None, timeout=60):
6325f35090dSAndrew Geissler        if hasattr(self, 'qmp') and self.qmp:
633*6aa7eec5SAndrew Geissler            self.qmp.settimeout(timeout)
6345f35090dSAndrew Geissler            if args is not None:
6355f35090dSAndrew Geissler                return self.qmp.cmd(command, args)
6365f35090dSAndrew Geissler            else:
637c926e17cSAndrew Geissler                return self.qmp.cmd(command)
638c926e17cSAndrew Geissler
639977dc1acSBrad Bishop    def run_serial(self, command, raw=False, timeout=60):
64092b42cb3SPatrick Williams        # Returns (status, output) where status is 1 on success and 0 on error
64192b42cb3SPatrick Williams
642eb8dc403SDave Cobbley        # We assume target system have echo to get command status
643eb8dc403SDave Cobbley        if not raw:
644eb8dc403SDave Cobbley            command = "%s; echo $?\n" % command
645eb8dc403SDave Cobbley
646eb8dc403SDave Cobbley        data = ''
647eb8dc403SDave Cobbley        status = 0
648eb8dc403SDave Cobbley        self.server_socket.sendall(command.encode('utf-8'))
649eb8dc403SDave Cobbley        start = time.time()
650eb8dc403SDave Cobbley        end = start + timeout
651eb8dc403SDave Cobbley        while True:
652eb8dc403SDave Cobbley            now = time.time()
653eb8dc403SDave Cobbley            if now >= end:
654eb8dc403SDave Cobbley                data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout
655eb8dc403SDave Cobbley                break
656eb8dc403SDave Cobbley            try:
657eb8dc403SDave Cobbley                sread, _, _ = select.select([self.server_socket],[],[], end - now)
658eb8dc403SDave Cobbley            except InterruptedError:
659eb8dc403SDave Cobbley                continue
660eb8dc403SDave Cobbley            if sread:
661*6aa7eec5SAndrew Geissler                # try to avoid reading single character at a time
662*6aa7eec5SAndrew Geissler                time.sleep(0.1)
663eb8dc403SDave Cobbley                answer = self.server_socket.recv(1024)
664eb8dc403SDave Cobbley                if answer:
665eb8dc403SDave Cobbley                    data += answer.decode('utf-8')
666eb8dc403SDave Cobbley                    # Search the prompt to stop
66782c905dcSAndrew Geissler                    if re.search(self.boot_patterns['search_cmd_finished'], data):
668eb8dc403SDave Cobbley                        break
669eb8dc403SDave Cobbley                else:
670ac69b488SWilliam A. Kennington III                    if self.canexit:
671ac69b488SWilliam A. Kennington III                        return (1, "")
672ac69b488SWilliam A. Kennington III                    raise Exception("No data on serial console socket, connection closed?")
673eb8dc403SDave Cobbley
674eb8dc403SDave Cobbley        if data:
675eb8dc403SDave Cobbley            if raw:
676eb8dc403SDave Cobbley                status = 1
677eb8dc403SDave Cobbley            else:
678eb8dc403SDave Cobbley                # Remove first line (command line) and last line (prompt)
679eb8dc403SDave Cobbley                data = data[data.find('$?\r\n')+4:data.rfind('\r\n')]
680eb8dc403SDave Cobbley                index = data.rfind('\r\n')
681eb8dc403SDave Cobbley                if index == -1:
682eb8dc403SDave Cobbley                    status_cmd = data
683eb8dc403SDave Cobbley                    data = ""
684eb8dc403SDave Cobbley                else:
685eb8dc403SDave Cobbley                    status_cmd = data[index+2:]
686eb8dc403SDave Cobbley                    data = data[:index]
687eb8dc403SDave Cobbley                if (status_cmd == "0"):
688eb8dc403SDave Cobbley                    status = 1
689eb8dc403SDave Cobbley        return (status, str(data))
690eb8dc403SDave Cobbley
691eb8dc403SDave Cobbley
692eb8dc403SDave Cobbley    def _dump_host(self):
693eb8dc403SDave Cobbley        self.host_dumper.create_dir("qemu")
6941a4b7ee2SBrad Bishop        self.logger.warning("Qemu ended unexpectedly, dump data from host"
695eb8dc403SDave Cobbley                " is in %s" % self.host_dumper.dump_dir)
696eb8dc403SDave Cobbley        self.host_dumper.dump_host()
697eb8dc403SDave Cobbley
698eb8dc403SDave Cobbley# This class is for reading data from a socket and passing it to logfunc
699eb8dc403SDave Cobbley# to be processed. It's completely event driven and has a straightforward
700eb8dc403SDave Cobbley# event loop. The mechanism for stopping the thread is a simple pipe which
701eb8dc403SDave Cobbley# will wake up the poll and allow for tearing everything down.
702eb8dc403SDave Cobbleyclass LoggingThread(threading.Thread):
703eb8dc403SDave Cobbley    def __init__(self, logfunc, sock, logger):
704eb8dc403SDave Cobbley        self.connection_established = threading.Event()
705eb8dc403SDave Cobbley        self.serversock = sock
706eb8dc403SDave Cobbley        self.logfunc = logfunc
707eb8dc403SDave Cobbley        self.logger = logger
708eb8dc403SDave Cobbley        self.readsock = None
709eb8dc403SDave Cobbley        self.running = False
710c926e17cSAndrew Geissler        self.canexit = False
711eb8dc403SDave Cobbley
712eb8dc403SDave Cobbley        self.errorevents = select.POLLERR | select.POLLHUP | select.POLLNVAL
713eb8dc403SDave Cobbley        self.readevents = select.POLLIN | select.POLLPRI
714eb8dc403SDave Cobbley
715eb8dc403SDave Cobbley        threading.Thread.__init__(self, target=self.threadtarget)
716eb8dc403SDave Cobbley
717eb8dc403SDave Cobbley    def threadtarget(self):
718eb8dc403SDave Cobbley        try:
719eb8dc403SDave Cobbley            self.eventloop()
720eb8dc403SDave Cobbley        finally:
721eb8dc403SDave Cobbley            self.teardown()
722eb8dc403SDave Cobbley
723eb8dc403SDave Cobbley    def run(self):
724eb8dc403SDave Cobbley        self.logger.debug("Starting logging thread")
725eb8dc403SDave Cobbley        self.readpipe, self.writepipe = os.pipe()
726eb8dc403SDave Cobbley        threading.Thread.run(self)
727eb8dc403SDave Cobbley
728eb8dc403SDave Cobbley    def stop(self):
729eb8dc403SDave Cobbley        self.logger.debug("Stopping logging thread")
730eb8dc403SDave Cobbley        if self.running:
731eb8dc403SDave Cobbley            os.write(self.writepipe, bytes("stop", "utf-8"))
732eb8dc403SDave Cobbley
733eb8dc403SDave Cobbley    def teardown(self):
734eb8dc403SDave Cobbley        self.logger.debug("Tearing down logging thread")
735eb8dc403SDave Cobbley        self.close_socket(self.serversock)
736eb8dc403SDave Cobbley
737eb8dc403SDave Cobbley        if self.readsock is not None:
738eb8dc403SDave Cobbley            self.close_socket(self.readsock)
739eb8dc403SDave Cobbley
740eb8dc403SDave Cobbley        self.close_ignore_error(self.readpipe)
741eb8dc403SDave Cobbley        self.close_ignore_error(self.writepipe)
742eb8dc403SDave Cobbley        self.running = False
743eb8dc403SDave Cobbley
744c926e17cSAndrew Geissler    def allowexit(self):
745c926e17cSAndrew Geissler        self.canexit = True
746c926e17cSAndrew Geissler
747eb8dc403SDave Cobbley    def eventloop(self):
748eb8dc403SDave Cobbley        poll = select.poll()
749eb8dc403SDave Cobbley        event_read_mask = self.errorevents | self.readevents
750eb8dc403SDave Cobbley        poll.register(self.serversock.fileno())
751eb8dc403SDave Cobbley        poll.register(self.readpipe, event_read_mask)
752eb8dc403SDave Cobbley
753eb8dc403SDave Cobbley        breakout = False
754eb8dc403SDave Cobbley        self.running = True
755eb8dc403SDave Cobbley        self.logger.debug("Starting thread event loop")
756eb8dc403SDave Cobbley        while not breakout:
757eb8dc403SDave Cobbley            events = poll.poll()
758eb8dc403SDave Cobbley            for event in events:
759eb8dc403SDave Cobbley                # An error occurred, bail out
760eb8dc403SDave Cobbley                if event[1] & self.errorevents:
761eb8dc403SDave Cobbley                    raise Exception(self.stringify_event(event[1]))
762eb8dc403SDave Cobbley
763eb8dc403SDave Cobbley                # Event to stop the thread
764eb8dc403SDave Cobbley                if self.readpipe == event[0]:
765eb8dc403SDave Cobbley                    self.logger.debug("Stop event received")
766eb8dc403SDave Cobbley                    breakout = True
767eb8dc403SDave Cobbley                    break
768eb8dc403SDave Cobbley
769eb8dc403SDave Cobbley                # A connection request was received
770eb8dc403SDave Cobbley                elif self.serversock.fileno() == event[0]:
771eb8dc403SDave Cobbley                    self.logger.debug("Connection request received")
772eb8dc403SDave Cobbley                    self.readsock, _ = self.serversock.accept()
773eb8dc403SDave Cobbley                    self.readsock.setblocking(0)
774eb8dc403SDave Cobbley                    poll.unregister(self.serversock.fileno())
775eb8dc403SDave Cobbley                    poll.register(self.readsock.fileno(), event_read_mask)
776eb8dc403SDave Cobbley
777eb8dc403SDave Cobbley                    self.logger.debug("Setting connection established event")
778eb8dc403SDave Cobbley                    self.connection_established.set()
779eb8dc403SDave Cobbley
780eb8dc403SDave Cobbley                # Actual data to be logged
781eb8dc403SDave Cobbley                elif self.readsock.fileno() == event[0]:
782eb8dc403SDave Cobbley                    data = self.recv(1024)
783eb8dc403SDave Cobbley                    self.logfunc(data)
784eb8dc403SDave Cobbley
785eb8dc403SDave Cobbley    # Since the socket is non-blocking make sure to honor EAGAIN
786eb8dc403SDave Cobbley    # and EWOULDBLOCK.
787eb8dc403SDave Cobbley    def recv(self, count):
788eb8dc403SDave Cobbley        try:
789eb8dc403SDave Cobbley            data = self.readsock.recv(count)
790eb8dc403SDave Cobbley        except socket.error as e:
791eb8dc403SDave Cobbley            if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK:
792ac69b488SWilliam A. Kennington III                return b''
793eb8dc403SDave Cobbley            else:
794eb8dc403SDave Cobbley                raise
795eb8dc403SDave Cobbley
796eb8dc403SDave Cobbley        if data is None:
797eb8dc403SDave Cobbley            raise Exception("No data on read ready socket")
798eb8dc403SDave Cobbley        elif not data:
799eb8dc403SDave Cobbley            # This actually means an orderly shutdown
800eb8dc403SDave Cobbley            # happened. But for this code it counts as an
801eb8dc403SDave Cobbley            # error since the connection shouldn't go away
802eb8dc403SDave Cobbley            # until qemu exits.
803c926e17cSAndrew Geissler            if not self.canexit:
804eb8dc403SDave Cobbley                raise Exception("Console connection closed unexpectedly")
805ac69b488SWilliam A. Kennington III            return b''
806eb8dc403SDave Cobbley
807eb8dc403SDave Cobbley        return data
808eb8dc403SDave Cobbley
809eb8dc403SDave Cobbley    def stringify_event(self, event):
810eb8dc403SDave Cobbley        val = ''
811eb8dc403SDave Cobbley        if select.POLLERR == event:
812eb8dc403SDave Cobbley            val = 'POLLER'
813eb8dc403SDave Cobbley        elif select.POLLHUP == event:
814eb8dc403SDave Cobbley            val = 'POLLHUP'
815eb8dc403SDave Cobbley        elif select.POLLNVAL == event:
816eb8dc403SDave Cobbley            val = 'POLLNVAL'
817eb8dc403SDave Cobbley        return val
818eb8dc403SDave Cobbley
819eb8dc403SDave Cobbley    def close_socket(self, sock):
820eb8dc403SDave Cobbley        sock.shutdown(socket.SHUT_RDWR)
821eb8dc403SDave Cobbley        sock.close()
822eb8dc403SDave Cobbley
823eb8dc403SDave Cobbley    def close_ignore_error(self, fd):
824eb8dc403SDave Cobbley        try:
825eb8dc403SDave Cobbley            os.close(fd)
826eb8dc403SDave Cobbley        except OSError:
827eb8dc403SDave Cobbley            pass
828