diff options
author | Richard Purdie <richard.purdie@linuxfoundation.org> | 2023-12-18 15:14:08 +0000 |
---|---|---|
committer | Richard Purdie <richard.purdie@linuxfoundation.org> | 2023-12-20 07:47:00 +0000 |
commit | 98b63ecc4358a11c6840bad90c86846b8b9a3a76 (patch) | |
tree | 9c7abff238af0ceba57c541959799a18e30be05e /meta/lib/oeqa/utils/qemurunner.py | |
parent | d921da782aed3fdf0b2c888751cc6e67618adc6a (diff) | |
download | poky-98b63ecc4358a11c6840bad90c86846b8b9a3a76.tar.gz |
qemurunner: Improve handling of serial port output blocking
Similar to stdout in the previous commit, we need to ensure serial output
if written is read and put somewhere, else qemu might block on writes to
the serial port leading to hangs in the kernel. Use our existing logging
thread to log data when run_serial is not in use.
(From OE-Core rev: 05761282ba31e4ba3594f7321e2162d01fe12a5f)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Diffstat (limited to 'meta/lib/oeqa/utils/qemurunner.py')
-rw-r--r-- | meta/lib/oeqa/utils/qemurunner.py | 98 |
1 files changed, 69 insertions, 29 deletions
diff --git a/meta/lib/oeqa/utils/qemurunner.py b/meta/lib/oeqa/utils/qemurunner.py index cdd0db5877..4a2246733f 100644 --- a/meta/lib/oeqa/utils/qemurunner.py +++ b/meta/lib/oeqa/utils/qemurunner.py | |||
@@ -21,7 +21,9 @@ import threading | |||
21 | import codecs | 21 | import codecs |
22 | import tempfile | 22 | import tempfile |
23 | from collections import defaultdict | 23 | from collections import defaultdict |
24 | from contextlib import contextmanager | ||
24 | import importlib | 25 | import importlib |
26 | import traceback | ||
25 | 27 | ||
26 | # Get Unicode non printable control chars | 28 | # Get Unicode non printable control chars |
27 | control_range = list(range(0,32))+list(range(127,160)) | 29 | control_range = list(range(0,32))+list(range(127,160)) |
@@ -517,8 +519,12 @@ class QemuRunner: | |||
517 | except Exception as e: | 519 | except Exception as e: |
518 | self.logger.warning('Extra log data exception %s' % repr(e)) | 520 | self.logger.warning('Extra log data exception %s' % repr(e)) |
519 | data = None | 521 | data = None |
522 | self.thread.serial_lock.release() | ||
520 | return False | 523 | return False |
521 | 524 | ||
525 | with self.thread.serial_lock: | ||
526 | self.thread.set_serialsock(self.server_socket) | ||
527 | |||
522 | # If we are not able to login the tests can continue | 528 | # If we are not able to login the tests can continue |
523 | try: | 529 | try: |
524 | (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120) | 530 | (status, output) = self.run_serial(self.boot_patterns['send_login_user'], raw=True, timeout=120) |
@@ -653,31 +659,32 @@ class QemuRunner: | |||
653 | 659 | ||
654 | data = '' | 660 | data = '' |
655 | status = 0 | 661 | status = 0 |
656 | self.server_socket.sendall(command.encode('utf-8')) | 662 | with self.thread.serial_lock: |
657 | start = time.time() | 663 | self.server_socket.sendall(command.encode('utf-8')) |
658 | end = start + timeout | 664 | start = time.time() |
659 | while True: | 665 | end = start + timeout |
660 | now = time.time() | 666 | while True: |
661 | if now >= end: | 667 | now = time.time() |
662 | data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout | 668 | if now >= end: |
663 | break | 669 | data += "<<< run_serial(): command timed out after %d seconds without output >>>\r\n\r\n" % timeout |
664 | try: | 670 | break |
665 | sread, _, _ = select.select([self.server_socket],[],[], end - now) | 671 | try: |
666 | except InterruptedError: | 672 | sread, _, _ = select.select([self.server_socket],[],[], end - now) |
667 | continue | 673 | except InterruptedError: |
668 | if sread: | 674 | continue |
669 | # try to avoid reading single character at a time | 675 | if sread: |
670 | time.sleep(0.1) | 676 | # try to avoid reading single character at a time |
671 | answer = self.server_socket.recv(1024) | 677 | time.sleep(0.1) |
672 | if answer: | 678 | answer = self.server_socket.recv(1024) |
673 | data += answer.decode('utf-8') | 679 | if answer: |
674 | # Search the prompt to stop | 680 | data += answer.decode('utf-8') |
675 | if re.search(self.boot_patterns['search_cmd_finished'], data): | 681 | # Search the prompt to stop |
676 | break | 682 | if re.search(self.boot_patterns['search_cmd_finished'], data): |
677 | else: | 683 | break |
678 | if self.canexit: | 684 | else: |
679 | return (1, "") | 685 | if self.canexit: |
680 | raise Exception("No data on serial console socket, connection closed?") | 686 | return (1, "") |
687 | raise Exception("No data on serial console socket, connection closed?") | ||
681 | 688 | ||
682 | if data: | 689 | if data: |
683 | if raw: | 690 | if raw: |
@@ -696,6 +703,15 @@ class QemuRunner: | |||
696 | status = 1 | 703 | status = 1 |
697 | return (status, str(data)) | 704 | return (status, str(data)) |
698 | 705 | ||
706 | @contextmanager | ||
707 | def nonblocking_lock(lock): | ||
708 | locked = lock.acquire(False) | ||
709 | try: | ||
710 | yield locked | ||
711 | finally: | ||
712 | if locked: | ||
713 | lock.release() | ||
714 | |||
699 | # This class is for reading data from a socket and passing it to logfunc | 715 | # This class is for reading data from a socket and passing it to logfunc |
700 | # to be processed. It's completely event driven and has a straightforward | 716 | # to be processed. It's completely event driven and has a straightforward |
701 | # event loop. The mechanism for stopping the thread is a simple pipe which | 717 | # event loop. The mechanism for stopping the thread is a simple pipe which |
@@ -703,8 +719,10 @@ class QemuRunner: | |||
703 | class LoggingThread(threading.Thread): | 719 | class LoggingThread(threading.Thread): |
704 | def __init__(self, logfunc, sock, logger, qemuoutput): | 720 | def __init__(self, logfunc, sock, logger, qemuoutput): |
705 | self.connection_established = threading.Event() | 721 | self.connection_established = threading.Event() |
722 | self.serial_lock = threading.Lock() | ||
706 | 723 | ||
707 | self.serversock = sock | 724 | self.serversock = sock |
725 | self.serialsock = None | ||
708 | self.qemuoutput = qemuoutput | 726 | self.qemuoutput = qemuoutput |
709 | self.logfunc = logfunc | 727 | self.logfunc = logfunc |
710 | self.logger = logger | 728 | self.logger = logger |
@@ -717,9 +735,14 @@ class LoggingThread(threading.Thread): | |||
717 | 735 | ||
718 | threading.Thread.__init__(self, target=self.threadtarget) | 736 | threading.Thread.__init__(self, target=self.threadtarget) |
719 | 737 | ||
738 | def set_serialsock(self, serialsock): | ||
739 | self.serialsock = serialsock | ||
740 | |||
720 | def threadtarget(self): | 741 | def threadtarget(self): |
721 | try: | 742 | try: |
722 | self.eventloop() | 743 | self.eventloop() |
744 | except Exception as e: | ||
745 | self.logger.warning("Exception %s in logging thread" % traceback.format_exception(e)) | ||
723 | finally: | 746 | finally: |
724 | self.teardown() | 747 | self.teardown() |
725 | 748 | ||
@@ -753,6 +776,7 @@ class LoggingThread(threading.Thread): | |||
753 | event_read_mask = self.errorevents | self.readevents | 776 | event_read_mask = self.errorevents | self.readevents |
754 | if self.serversock: | 777 | if self.serversock: |
755 | poll.register(self.serversock.fileno()) | 778 | poll.register(self.serversock.fileno()) |
779 | serial_registered = False | ||
756 | poll.register(self.qemuoutput.fileno()) | 780 | poll.register(self.qemuoutput.fileno()) |
757 | poll.register(self.readpipe, event_read_mask) | 781 | poll.register(self.readpipe, event_read_mask) |
758 | 782 | ||
@@ -760,7 +784,7 @@ class LoggingThread(threading.Thread): | |||
760 | self.running = True | 784 | self.running = True |
761 | self.logger.debug("Starting thread event loop") | 785 | self.logger.debug("Starting thread event loop") |
762 | while not breakout: | 786 | while not breakout: |
763 | events = poll.poll() | 787 | events = poll.poll(2) |
764 | for event in events: | 788 | for event in events: |
765 | # An error occurred, bail out | 789 | # An error occurred, bail out |
766 | if event[1] & self.errorevents: | 790 | if event[1] & self.errorevents: |
@@ -785,18 +809,34 @@ class LoggingThread(threading.Thread): | |||
785 | 809 | ||
786 | # Actual data to be logged | 810 | # Actual data to be logged |
787 | elif self.readsock.fileno() == event[0]: | 811 | elif self.readsock.fileno() == event[0]: |
788 | data = self.recv(1024) | 812 | data = self.recv(1024, self.readsock) |
789 | self.logfunc(data) | 813 | self.logfunc(data) |
790 | elif self.qemuoutput.fileno() == event[0]: | 814 | elif self.qemuoutput.fileno() == event[0]: |
791 | data = self.qemuoutput.read() | 815 | data = self.qemuoutput.read() |
792 | self.logger.debug("Data received on qemu stdout %s" % data) | 816 | self.logger.debug("Data received on qemu stdout %s" % data) |
793 | self.logfunc(data, ".stdout") | 817 | self.logfunc(data, ".stdout") |
818 | elif self.serialsock and self.serialsock.fileno() == event[0]: | ||
819 | if self.serial_lock.acquire(blocking=False): | ||
820 | data = self.recv(1024, self.serialsock) | ||
821 | self.logger.debug("Data received serial thread %s" % data.decode('utf-8', 'replace')) | ||
822 | self.logfunc(data, ".2") | ||
823 | self.serial_lock.release() | ||
824 | else: | ||
825 | serial_registered = False | ||
826 | poll.unregister(self.serialsock.fileno()) | ||
827 | |||
828 | if not serial_registered and self.serialsock: | ||
829 | with nonblocking_lock(self.serial_lock) as l: | ||
830 | if l: | ||
831 | serial_registered = True | ||
832 | poll.register(self.serialsock.fileno(), event_read_mask) | ||
833 | |||
794 | 834 | ||
795 | # Since the socket is non-blocking make sure to honor EAGAIN | 835 | # Since the socket is non-blocking make sure to honor EAGAIN |
796 | # and EWOULDBLOCK. | 836 | # and EWOULDBLOCK. |
797 | def recv(self, count): | 837 | def recv(self, count, sock): |
798 | try: | 838 | try: |
799 | data = self.readsock.recv(count) | 839 | data = sock.recv(count) |
800 | except socket.error as e: | 840 | except socket.error as e: |
801 | if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK: | 841 | if e.errno == errno.EAGAIN or e.errno == errno.EWOULDBLOCK: |
802 | return b'' | 842 | return b'' |