iotests: Set up Python logging
[qemu/kevin.git] / tests / qemu-iotests / iotests.py
blob36a7757aafb0b3deeac30e142d6e73b15a8c39e9
1 # Common utilities and Python wrappers for qemu-iotests
3 # Copyright (C) 2012 IBM Corp.
5 # This program is free software; you can redistribute it and/or modify
6 # it under the terms of the GNU General Public License as published by
7 # the Free Software Foundation; either version 2 of the License, or
8 # (at your option) any later version.
10 # This program is distributed in the hope that it will be useful,
11 # but WITHOUT ANY WARRANTY; without even the implied warranty of
12 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
13 # GNU General Public License for more details.
15 # You should have received a copy of the GNU General Public License
16 # along with this program. If not, see <http://www.gnu.org/licenses/>.
19 import errno
20 import os
21 import re
22 import subprocess
23 import string
24 import unittest
25 import sys
26 sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..', 'scripts'))
27 import qtest
28 import struct
29 import json
30 import signal
31 import logging
34 # This will not work if arguments contain spaces but is necessary if we
35 # want to support the override options that ./check supports.
36 qemu_img_args = [os.environ.get('QEMU_IMG_PROG', 'qemu-img')]
37 if os.environ.get('QEMU_IMG_OPTIONS'):
38 qemu_img_args += os.environ['QEMU_IMG_OPTIONS'].strip().split(' ')
40 qemu_io_args = [os.environ.get('QEMU_IO_PROG', 'qemu-io')]
41 if os.environ.get('QEMU_IO_OPTIONS'):
42 qemu_io_args += os.environ['QEMU_IO_OPTIONS'].strip().split(' ')
44 qemu_nbd_args = [os.environ.get('QEMU_NBD_PROG', 'qemu-nbd')]
45 if os.environ.get('QEMU_NBD_OPTIONS'):
46 qemu_nbd_args += os.environ['QEMU_NBD_OPTIONS'].strip().split(' ')
48 qemu_prog = os.environ.get('QEMU_PROG', 'qemu')
49 qemu_opts = os.environ.get('QEMU_OPTIONS', '').strip().split(' ')
51 imgfmt = os.environ.get('IMGFMT', 'raw')
52 imgproto = os.environ.get('IMGPROTO', 'file')
53 test_dir = os.environ.get('TEST_DIR')
54 output_dir = os.environ.get('OUTPUT_DIR', '.')
55 cachemode = os.environ.get('CACHEMODE')
56 qemu_default_machine = os.environ.get('QEMU_DEFAULT_MACHINE')
58 socket_scm_helper = os.environ.get('SOCKET_SCM_HELPER', 'socket_scm_helper')
59 debug = False
61 def qemu_img(*args):
62 '''Run qemu-img and return the exit code'''
63 devnull = open('/dev/null', 'r+')
64 exitcode = subprocess.call(qemu_img_args + list(args), stdin=devnull, stdout=devnull)
65 if exitcode < 0:
66 sys.stderr.write('qemu-img received signal %i: %s\n' % (-exitcode, ' '.join(qemu_img_args + list(args))))
67 return exitcode
69 def qemu_img_verbose(*args):
70 '''Run qemu-img without suppressing its output and return the exit code'''
71 exitcode = subprocess.call(qemu_img_args + list(args))
72 if exitcode < 0:
73 sys.stderr.write('qemu-img received signal %i: %s\n' % (-exitcode, ' '.join(qemu_img_args + list(args))))
74 return exitcode
76 def qemu_img_pipe(*args):
77 '''Run qemu-img and return its output'''
78 subp = subprocess.Popen(qemu_img_args + list(args),
79 stdout=subprocess.PIPE,
80 stderr=subprocess.STDOUT)
81 exitcode = subp.wait()
82 if exitcode < 0:
83 sys.stderr.write('qemu-img received signal %i: %s\n' % (-exitcode, ' '.join(qemu_img_args + list(args))))
84 return subp.communicate()[0]
86 def qemu_io(*args):
87 '''Run qemu-io and return the stdout data'''
88 args = qemu_io_args + list(args)
89 subp = subprocess.Popen(args, stdout=subprocess.PIPE,
90 stderr=subprocess.STDOUT)
91 exitcode = subp.wait()
92 if exitcode < 0:
93 sys.stderr.write('qemu-io received signal %i: %s\n' % (-exitcode, ' '.join(args)))
94 return subp.communicate()[0]
96 def qemu_nbd(*args):
97 '''Run qemu-nbd in daemon mode and return the parent's exit code'''
98 return subprocess.call(qemu_nbd_args + ['--fork'] + list(args))
100 def compare_images(img1, img2, fmt1=imgfmt, fmt2=imgfmt):
101 '''Return True if two image files are identical'''
102 return qemu_img('compare', '-f', fmt1,
103 '-F', fmt2, img1, img2) == 0
105 def create_image(name, size):
106 '''Create a fully-allocated raw image with sector markers'''
107 file = open(name, 'w')
108 i = 0
109 while i < size:
110 sector = struct.pack('>l504xl', i / 512, i / 512)
111 file.write(sector)
112 i = i + 512
113 file.close()
115 def image_size(img):
116 '''Return image's virtual size'''
117 r = qemu_img_pipe('info', '--output=json', '-f', imgfmt, img)
118 return json.loads(r)['virtual-size']
120 test_dir_re = re.compile(r"%s" % test_dir)
121 def filter_test_dir(msg):
122 return test_dir_re.sub("TEST_DIR", msg)
124 win32_re = re.compile(r"\r")
125 def filter_win32(msg):
126 return win32_re.sub("", msg)
128 qemu_io_re = re.compile(r"[0-9]* ops; [0-9\/:. sec]* \([0-9\/.inf]* [EPTGMKiBbytes]*\/sec and [0-9\/.inf]* ops\/sec\)")
129 def filter_qemu_io(msg):
130 msg = filter_win32(msg)
131 return qemu_io_re.sub("X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)", msg)
133 chown_re = re.compile(r"chown [0-9]+:[0-9]+")
134 def filter_chown(msg):
135 return chown_re.sub("chown UID:GID", msg)
137 def filter_qmp_event(event):
138 '''Filter a QMP event dict'''
139 event = dict(event)
140 if 'timestamp' in event:
141 event['timestamp']['seconds'] = 'SECS'
142 event['timestamp']['microseconds'] = 'USECS'
143 return event
145 def log(msg, filters=[]):
146 for flt in filters:
147 msg = flt(msg)
148 print msg
150 class Timeout:
151 def __init__(self, seconds, errmsg = "Timeout"):
152 self.seconds = seconds
153 self.errmsg = errmsg
154 def __enter__(self):
155 signal.signal(signal.SIGALRM, self.timeout)
156 signal.setitimer(signal.ITIMER_REAL, self.seconds)
157 return self
158 def __exit__(self, type, value, traceback):
159 signal.setitimer(signal.ITIMER_REAL, 0)
160 return False
161 def timeout(self, signum, frame):
162 raise Exception(self.errmsg)
165 class FilePath(object):
166 '''An auto-generated filename that cleans itself up.
168 Use this context manager to generate filenames and ensure that the file
169 gets deleted::
171 with TestFilePath('test.img') as img_path:
172 qemu_img('create', img_path, '1G')
173 # migration_sock_path is automatically deleted
175 def __init__(self, name):
176 filename = '{0}-{1}'.format(os.getpid(), name)
177 self.path = os.path.join(test_dir, filename)
179 def __enter__(self):
180 return self.path
182 def __exit__(self, exc_type, exc_val, exc_tb):
183 try:
184 os.remove(self.path)
185 except OSError:
186 pass
187 return False
190 class VM(qtest.QEMUQtestMachine):
191 '''A QEMU VM'''
193 def __init__(self, path_suffix=''):
194 name = "qemu%s-%d" % (path_suffix, os.getpid())
195 super(VM, self).__init__(qemu_prog, qemu_opts, name=name,
196 test_dir=test_dir,
197 socket_scm_helper=socket_scm_helper)
198 if debug:
199 self._debug = True
200 self._num_drives = 0
202 def add_device(self, opts):
203 self._args.append('-device')
204 self._args.append(opts)
205 return self
207 def add_drive_raw(self, opts):
208 self._args.append('-drive')
209 self._args.append(opts)
210 return self
212 def add_drive(self, path, opts='', interface='virtio', format=imgfmt):
213 '''Add a virtio-blk drive to the VM'''
214 options = ['if=%s' % interface,
215 'id=drive%d' % self._num_drives]
217 if path is not None:
218 options.append('file=%s' % path)
219 options.append('format=%s' % format)
220 options.append('cache=%s' % cachemode)
222 if opts:
223 options.append(opts)
225 self._args.append('-drive')
226 self._args.append(','.join(options))
227 self._num_drives += 1
228 return self
230 def add_blockdev(self, opts):
231 self._args.append('-blockdev')
232 if isinstance(opts, str):
233 self._args.append(opts)
234 else:
235 self._args.append(','.join(opts))
236 return self
238 def add_incoming(self, addr):
239 self._args.append('-incoming')
240 self._args.append(addr)
241 return self
243 def pause_drive(self, drive, event=None):
244 '''Pause drive r/w operations'''
245 if not event:
246 self.pause_drive(drive, "read_aio")
247 self.pause_drive(drive, "write_aio")
248 return
249 self.qmp('human-monitor-command',
250 command_line='qemu-io %s "break %s bp_%s"' % (drive, event, drive))
252 def resume_drive(self, drive):
253 self.qmp('human-monitor-command',
254 command_line='qemu-io %s "remove_break bp_%s"' % (drive, drive))
256 def hmp_qemu_io(self, drive, cmd):
257 '''Write to a given drive using an HMP command'''
258 return self.qmp('human-monitor-command',
259 command_line='qemu-io %s "%s"' % (drive, cmd))
262 index_re = re.compile(r'([^\[]+)\[([^\]]+)\]')
264 class QMPTestCase(unittest.TestCase):
265 '''Abstract base class for QMP test cases'''
267 def dictpath(self, d, path):
268 '''Traverse a path in a nested dict'''
269 for component in path.split('/'):
270 m = index_re.match(component)
271 if m:
272 component, idx = m.groups()
273 idx = int(idx)
275 if not isinstance(d, dict) or component not in d:
276 self.fail('failed path traversal for "%s" in "%s"' % (path, str(d)))
277 d = d[component]
279 if m:
280 if not isinstance(d, list):
281 self.fail('path component "%s" in "%s" is not a list in "%s"' % (component, path, str(d)))
282 try:
283 d = d[idx]
284 except IndexError:
285 self.fail('invalid index "%s" in path "%s" in "%s"' % (idx, path, str(d)))
286 return d
288 def flatten_qmp_object(self, obj, output=None, basestr=''):
289 if output is None:
290 output = dict()
291 if isinstance(obj, list):
292 for i in range(len(obj)):
293 self.flatten_qmp_object(obj[i], output, basestr + str(i) + '.')
294 elif isinstance(obj, dict):
295 for key in obj:
296 self.flatten_qmp_object(obj[key], output, basestr + key + '.')
297 else:
298 output[basestr[:-1]] = obj # Strip trailing '.'
299 return output
301 def qmp_to_opts(self, obj):
302 obj = self.flatten_qmp_object(obj)
303 output_list = list()
304 for key in obj:
305 output_list += [key + '=' + obj[key]]
306 return ','.join(output_list)
308 def assert_qmp_absent(self, d, path):
309 try:
310 result = self.dictpath(d, path)
311 except AssertionError:
312 return
313 self.fail('path "%s" has value "%s"' % (path, str(result)))
315 def assert_qmp(self, d, path, value):
316 '''Assert that the value for a specific path in a QMP dict matches'''
317 result = self.dictpath(d, path)
318 self.assertEqual(result, value, 'values not equal "%s" and "%s"' % (str(result), str(value)))
320 def assert_no_active_block_jobs(self):
321 result = self.vm.qmp('query-block-jobs')
322 self.assert_qmp(result, 'return', [])
324 def assert_has_block_node(self, node_name=None, file_name=None):
325 """Issue a query-named-block-nodes and assert node_name and/or
326 file_name is present in the result"""
327 def check_equal_or_none(a, b):
328 return a == None or b == None or a == b
329 assert node_name or file_name
330 result = self.vm.qmp('query-named-block-nodes')
331 for x in result["return"]:
332 if check_equal_or_none(x.get("node-name"), node_name) and \
333 check_equal_or_none(x.get("file"), file_name):
334 return
335 self.assertTrue(False, "Cannot find %s %s in result:\n%s" % \
336 (node_name, file_name, result))
338 def assert_json_filename_equal(self, json_filename, reference):
339 '''Asserts that the given filename is a json: filename and that its
340 content is equal to the given reference object'''
341 self.assertEqual(json_filename[:5], 'json:')
342 self.assertEqual(self.flatten_qmp_object(json.loads(json_filename[5:])),
343 self.flatten_qmp_object(reference))
345 def cancel_and_wait(self, drive='drive0', force=False, resume=False):
346 '''Cancel a block job and wait for it to finish, returning the event'''
347 result = self.vm.qmp('block-job-cancel', device=drive, force=force)
348 self.assert_qmp(result, 'return', {})
350 if resume:
351 self.vm.resume_drive(drive)
353 cancelled = False
354 result = None
355 while not cancelled:
356 for event in self.vm.get_qmp_events(wait=True):
357 if event['event'] == 'BLOCK_JOB_COMPLETED' or \
358 event['event'] == 'BLOCK_JOB_CANCELLED':
359 self.assert_qmp(event, 'data/device', drive)
360 result = event
361 cancelled = True
363 self.assert_no_active_block_jobs()
364 return result
366 def wait_until_completed(self, drive='drive0', check_offset=True):
367 '''Wait for a block job to finish, returning the event'''
368 completed = False
369 while not completed:
370 for event in self.vm.get_qmp_events(wait=True):
371 if event['event'] == 'BLOCK_JOB_COMPLETED':
372 self.assert_qmp(event, 'data/device', drive)
373 self.assert_qmp_absent(event, 'data/error')
374 if check_offset:
375 self.assert_qmp(event, 'data/offset', event['data']['len'])
376 completed = True
378 self.assert_no_active_block_jobs()
379 return event
381 def wait_ready(self, drive='drive0'):
382 '''Wait until a block job BLOCK_JOB_READY event'''
383 f = {'data': {'type': 'mirror', 'device': drive } }
384 event = self.vm.event_wait(name='BLOCK_JOB_READY', match=f)
386 def wait_ready_and_cancel(self, drive='drive0'):
387 self.wait_ready(drive=drive)
388 event = self.cancel_and_wait(drive=drive)
389 self.assertEquals(event['event'], 'BLOCK_JOB_COMPLETED')
390 self.assert_qmp(event, 'data/type', 'mirror')
391 self.assert_qmp(event, 'data/offset', event['data']['len'])
393 def complete_and_wait(self, drive='drive0', wait_ready=True):
394 '''Complete a block job and wait for it to finish'''
395 if wait_ready:
396 self.wait_ready(drive=drive)
398 result = self.vm.qmp('block-job-complete', device=drive)
399 self.assert_qmp(result, 'return', {})
401 event = self.wait_until_completed(drive=drive)
402 self.assert_qmp(event, 'data/type', 'mirror')
404 def pause_job(self, job_id='job0'):
405 result = self.vm.qmp('block-job-pause', device=job_id)
406 self.assert_qmp(result, 'return', {})
408 with Timeout(1, "Timeout waiting for job to pause"):
409 while True:
410 result = self.vm.qmp('query-block-jobs')
411 for job in result['return']:
412 if job['device'] == job_id and job['paused'] == True and job['busy'] == False:
413 return job
416 def notrun(reason):
417 '''Skip this test suite'''
418 # Each test in qemu-iotests has a number ("seq")
419 seq = os.path.basename(sys.argv[0])
421 open('%s/%s.notrun' % (output_dir, seq), 'wb').write(reason + '\n')
422 print '%s not run: %s' % (seq, reason)
423 sys.exit(0)
425 def verify_image_format(supported_fmts=[], unsupported_fmts=[]):
426 if supported_fmts and (imgfmt not in supported_fmts):
427 notrun('not suitable for this image format: %s' % imgfmt)
428 if unsupported_fmts and (imgfmt in unsupported_fmts):
429 notrun('not suitable for this image format: %s' % imgfmt)
431 def verify_platform(supported_oses=['linux']):
432 if True not in [sys.platform.startswith(x) for x in supported_oses]:
433 notrun('not suitable for this OS: %s' % sys.platform)
435 def supports_quorum():
436 return 'quorum' in qemu_img_pipe('--help')
438 def verify_quorum():
439 '''Skip test suite if quorum support is not available'''
440 if not supports_quorum():
441 notrun('quorum support missing')
443 def main(supported_fmts=[], supported_oses=['linux']):
444 '''Run tests'''
446 global debug
448 # We are using TEST_DIR and QEMU_DEFAULT_MACHINE as proxies to
449 # indicate that we're not being run via "check". There may be
450 # other things set up by "check" that individual test cases rely
451 # on.
452 if test_dir is None or qemu_default_machine is None:
453 sys.stderr.write('Please run this test via the "check" script\n')
454 sys.exit(os.EX_USAGE)
456 debug = '-d' in sys.argv
457 verbosity = 1
458 verify_image_format(supported_fmts)
459 verify_platform(supported_oses)
461 # We need to filter out the time taken from the output so that qemu-iotest
462 # can reliably diff the results against master output.
463 import StringIO
464 if debug:
465 output = sys.stdout
466 verbosity = 2
467 sys.argv.remove('-d')
468 else:
469 output = StringIO.StringIO()
471 logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN))
473 class MyTestRunner(unittest.TextTestRunner):
474 def __init__(self, stream=output, descriptions=True, verbosity=verbosity):
475 unittest.TextTestRunner.__init__(self, stream, descriptions, verbosity)
477 # unittest.main() will use sys.exit() so expect a SystemExit exception
478 try:
479 unittest.main(testRunner=MyTestRunner)
480 finally:
481 if not debug:
482 sys.stderr.write(re.sub(r'Ran (\d+) tests? in [\d.]+s', r'Ran \1 tests', output.getvalue()))