From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:39048) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1YjAvd-00069w-Nr for qemu-devel@nongnu.org; Fri, 17 Apr 2015 14:23:51 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1YjAvY-00050O-Jv for qemu-devel@nongnu.org; Fri, 17 Apr 2015 14:23:49 -0400 Message-ID: <55314FAD.6040009@redhat.com> Date: Fri, 17 Apr 2015 14:23:41 -0400 From: John Snow MIME-Version: 1.0 References: <1428531604-9428-1-git-send-email-jsnow@redhat.com> <1428531604-9428-19-git-send-email-jsnow@redhat.com> <55310BB0.3010704@redhat.com> In-Reply-To: <55310BB0.3010704@redhat.com> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit Subject: Re: [Qemu-devel] [PATCH v5 18/21] iotests: add QMP event waiting queue List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Max Reitz , qemu-block@nongnu.org Cc: kwolf@redhat.com, famz@redhat.com, qemu-devel@nongnu.org, armbru@redhat.com, vsementsov@parallels.com, stefanha@redhat.com On 04/17/2015 09:33 AM, Max Reitz wrote: > On 09.04.2015 00:20, John Snow wrote: >> A filter is added to allow callers to request very specific >> events to be pulled from the event queue, while leaving undesired >> events still in the stream. >> >> This allows to poll for completion data for multiple asynchronous >> events in any arbitrary order. >> >> A new timeout context is added to the qmp pull_event method's >> wait parameter to allow tests to fail if they do not complete >> within some expected period of time. >> >> Signed-off-by: John Snow >> --- >> scripts/qmp/qmp.py | 6 +++++- >> tests/qemu-iotests/iotests.py | 38 >> ++++++++++++++++++++++++++++++++++++++ >> 2 files changed, 43 insertions(+), 1 deletion(-) >> >> diff --git a/scripts/qmp/qmp.py b/scripts/qmp/qmp.py >> index 20b6ec7..7f9ac1b 100644 >> --- a/scripts/qmp/qmp.py >> +++ b/scripts/qmp/qmp.py >> @@ -140,7 +140,8 @@ class QEMUMonitorProtocol: >> """ >> Get and delete the first available QMP event. >> - @param wait: block until an event is available (bool) >> + @param wait: block until an event is available. If a float is >> provided, >> + use this as a timeout value. (bool, float) > > Ouch... I guess it works, though... > It does read awkwardly in the declaration, but I also thought that: wait=False wait=True wait=60.0 wait=0.0 all read fairly clearly and had very clear implications, so from a usage standpoint it seemed very nice and convenient. Making a second parameter gets strange: wait=False, timeout=50.0 ^ What does this mean? wait=True, timeout=0.0 ^ Does this mean to wait forever, or to not wait at all? So in this case I stand by what looks like hackishness as a nice, semantically appropriate interface. >> """ >> self.__sock.setblocking(0) >> try: >> @@ -151,7 +152,10 @@ class QEMUMonitorProtocol: >> pass >> self.__sock.setblocking(1) >> if not self.__events and wait: >> + if isinstance(wait, float): >> + self.__sock.settimeout(wait) >> self.__json_read(only_event=True) >> + self.__sock.settimeout(None) > > If a timeout occurs, __json_read will do nothing and return (I guess...). > It will actually throw an exception. >> event = self.__events[0] > > This will therefore probably return None... > So we'll never make it this far. >> del self.__events[0] > > And I don't know what this will do. Will it be a no-op? > Better than a no-op! >> return event >> diff --git a/tests/qemu-iotests/iotests.py >> b/tests/qemu-iotests/iotests.py >> index 1402854..e93e623 100644 >> --- a/tests/qemu-iotests/iotests.py >> +++ b/tests/qemu-iotests/iotests.py >> @@ -78,6 +78,23 @@ def create_image(name, size): >> i = i + 512 >> file.close() >> +# Test if 'match' is a recursive subset of 'event' >> +def event_match(event, match=None): >> + if match is None: >> + return True >> + >> + for key in match: >> + if key in event: >> + if isinstance(event[key], dict): >> + if not event_match(event[key], match[key]): >> + return False >> + elif event[key] != match[key]: >> + return False >> + else: >> + return False >> + >> + return True >> + >> class VM(object): >> '''A QEMU VM''' >> @@ -92,6 +109,7 @@ class VM(object): >> '-machine', 'accel=qtest', >> '-display', 'none', '-vga', 'none'] >> self._num_drives = 0 >> + self._events = [] >> # This can be used to add an unused monitor instance. >> def add_monitor_telnet(self, ip, port): >> @@ -202,14 +220,34 @@ class VM(object): >> def get_qmp_event(self, wait=False): >> '''Poll for one queued QMP events and return it''' >> + if len(self._events) > 0: >> + return self._events.pop(0) >> return self._qmp.pull_event(wait=wait) >> def get_qmp_events(self, wait=False): >> '''Poll for queued QMP events and return a list of dicts''' >> events = self._qmp.get_events(wait=wait) >> + events.extend(self._events) >> + del self._events[:] >> self._qmp.clear_events() >> return events >> + def event_wait(self, name='BLOCK_JOB_COMPLETED', timeout=60.0, >> match=None): >> + # Search cached events >> + for event in self._events: >> + if (event['event'] == name) and event_match(event, match): >> + self._events.remove(event) >> + return event >> + >> + # Poll for new events >> + while True: >> + event = self._qmp.pull_event(wait=timeout) > > So if a timeout occurred, event will probably be None. > >> + if (event['event'] == name) and event_match(event, match): > > And this (indexing event == None) will probably generate an exception. I > guess it's one way to fail the test, but certainly not the best... > > Max > In practice, the timeout throws a socket.timeout exception I don't bother to catch, so execution of the test will fail at this point, which is acceptable. Here's what happens in the next patch if I modify 'do_qmp_backup' to wait for a made up event that will never happen: event = self.vm.event_wait(name="JOHN_SNOW_CHECKS_IN_A_21_PATCH_SERIES", match={'data': {'device': kwargs['device']}}) self.assertIsNotNone(event) +====================================================================== +ERROR: test_incremental_simple (__main__.TestIncrementalBackup) +---------------------------------------------------------------------- +Traceback (most recent call last): + File "124", line 223, in test_incremental_simple + self.create_anchor_backup() + File "124", line 146, in create_anchor_backup + format=drive['fmt'], target=drive['backup']) + File "124", line 127, in do_qmp_backup + match={'data': {'device': kwargs['device']}}) + File "/home/bos/jhuston/src/qemu/tests/qemu-iotests/iotests.py", line 244, in event_wait + event = self._qmp.pull_event(wait=timeout) + File "/home/bos/jhuston/src/qemu/tests/qemu-iotests/../../scripts/qmp/qmp.py", line 157, in pull_event + self.__json_read(only_event=True) + File "/home/bos/jhuston/src/qemu/tests/qemu-iotests/../../scripts/qmp/qmp.py", line 63, in __json_read + data = self.__sockfile.readline() + File "/usr/lib64/python2.7/socket.py", line 447, in readline + data = self._sock.recv(self._rbufsize) +timeout: timed out + Python tracebacks are still awful to read, but you can see we failed due to a timeout. Hmm, though... I am now noticing that pull_event will definitely fail if you decide not to wait and there are no items in the queue, so... I think I will rewrite some of qmp.py while I'm here, and I'll make the error for timeout a little nicer for the end user. >> + return event >> + self._events.append(event) >> + >> + return None >> + >> index_re = re.compile(r'([^\[]+)\[([^\]]+)\]') >> class QMPTestCase(unittest.TestCase): > >