* [Qemu-devel] [PATCH 0/2] iotests: use python logging @ 2019-07-26 22:51 John Snow 2019-07-26 22:52 ` [Qemu-devel] [PATCH 1/2] iotests: add script_initialize John Snow 2019-07-26 22:52 ` [Qemu-devel] [PATCH 2/2] iotests: use python logging for iotests.log() John Snow 0 siblings, 2 replies; 7+ messages in thread From: John Snow @ 2019-07-26 22:51 UTC (permalink / raw) To: qemu-devel, qemu-block; +Cc: Kevin Wolf, John Snow, ehabkost, Max Reitz Based-on: https://github.com/jnsnow/qemu/tree/bitmaps This is a quick hack-em-up of what it might look like to use python logging to enable output conditionally on iotests.log(). We unify an initialization call (which also enables debugging output for those tests with -d) and then make the switch inside of iotests. It might help with needing to add logged/unlogged versions. Depends on my bitmaps branch, because of the iotests refactoring I have done there. John Snow (2): iotests: add script_initialize iotests: use python logging for iotests.log() tests/qemu-iotests/030 | 4 +-- tests/qemu-iotests/149 | 3 +- tests/qemu-iotests/194 | 3 +- tests/qemu-iotests/202 | 3 +- tests/qemu-iotests/203 | 3 +- tests/qemu-iotests/206 | 2 +- tests/qemu-iotests/208 | 2 +- tests/qemu-iotests/216 | 3 +- tests/qemu-iotests/218 | 2 +- tests/qemu-iotests/219 | 2 +- tests/qemu-iotests/222 | 5 ++- tests/qemu-iotests/224 | 3 +- tests/qemu-iotests/228 | 3 +- tests/qemu-iotests/234 | 3 +- tests/qemu-iotests/235 | 4 +-- tests/qemu-iotests/236 | 2 +- tests/qemu-iotests/238 | 2 ++ tests/qemu-iotests/242 | 2 +- tests/qemu-iotests/245 | 1 + tests/qemu-iotests/245.out | 24 ++++++------- tests/qemu-iotests/246 | 2 +- tests/qemu-iotests/248 | 2 +- tests/qemu-iotests/254 | 2 +- tests/qemu-iotests/255 | 2 +- tests/qemu-iotests/256 | 2 +- tests/qemu-iotests/iotests.py | 67 ++++++++++++++++++++++------------- 26 files changed, 83 insertions(+), 70 deletions(-) -- 2.21.0 ^ permalink raw reply [flat|nested] 7+ messages in thread
* [Qemu-devel] [PATCH 1/2] iotests: add script_initialize 2019-07-26 22:51 [Qemu-devel] [PATCH 0/2] iotests: use python logging John Snow @ 2019-07-26 22:52 ` John Snow 2019-07-29 0:07 ` Eduardo Habkost 2019-07-26 22:52 ` [Qemu-devel] [PATCH 2/2] iotests: use python logging for iotests.log() John Snow 1 sibling, 1 reply; 7+ messages in thread From: John Snow @ 2019-07-26 22:52 UTC (permalink / raw) To: qemu-devel, qemu-block; +Cc: Kevin Wolf, John Snow, ehabkost, Max Reitz Like script_main, but doesn't require a single point of entry. Replace all existing initialization sections with this drop-in replacement. This brings debug support to all existing script-style iotests. Note: supported_oses=['linux'] was omitted, as it is a default argument. Signed-off-by: John Snow <jsnow@redhat.com> --- tests/qemu-iotests/149 | 3 +-- tests/qemu-iotests/194 | 3 +-- tests/qemu-iotests/202 | 3 +-- tests/qemu-iotests/203 | 3 +-- tests/qemu-iotests/206 | 2 +- tests/qemu-iotests/208 | 2 +- tests/qemu-iotests/216 | 3 +-- tests/qemu-iotests/218 | 2 +- tests/qemu-iotests/219 | 2 +- tests/qemu-iotests/222 | 5 ++--- tests/qemu-iotests/224 | 3 +-- tests/qemu-iotests/228 | 3 +-- tests/qemu-iotests/234 | 3 +-- tests/qemu-iotests/235 | 4 ++-- tests/qemu-iotests/236 | 2 +- tests/qemu-iotests/238 | 2 ++ tests/qemu-iotests/242 | 2 +- tests/qemu-iotests/246 | 2 +- tests/qemu-iotests/248 | 2 +- tests/qemu-iotests/254 | 2 +- tests/qemu-iotests/255 | 2 +- tests/qemu-iotests/256 | 2 +- tests/qemu-iotests/iotests.py | 19 +++++++++++++++---- 23 files changed, 40 insertions(+), 36 deletions(-) diff --git a/tests/qemu-iotests/149 b/tests/qemu-iotests/149 index 4f363f295f..9fa97966c5 100755 --- a/tests/qemu-iotests/149 +++ b/tests/qemu-iotests/149 @@ -383,8 +383,7 @@ def test_once(config, qemu_img=False): # Obviously we only work with the luks image format -iotests.verify_image_format(supported_fmts=['luks']) -iotests.verify_platform() +iotests.script_initialize(supported_fmts=['luks']) # We need sudo in order to run cryptsetup to create # dm-crypt devices. This is safe to use on any diff --git a/tests/qemu-iotests/194 b/tests/qemu-iotests/194 index d746ab1e21..c8aeb6d0e4 100755 --- a/tests/qemu-iotests/194 +++ b/tests/qemu-iotests/194 @@ -21,8 +21,7 @@ import iotests -iotests.verify_image_format(supported_fmts=['qcow2', 'qed', 'raw']) -iotests.verify_platform(['linux']) +iotests.script_initialize(supported_fmts=['qcow2', 'qed', 'raw']) with iotests.FilePath('source.img') as source_img_path, \ iotests.FilePath('dest.img') as dest_img_path, \ diff --git a/tests/qemu-iotests/202 b/tests/qemu-iotests/202 index 581ca34d79..1271ac9459 100755 --- a/tests/qemu-iotests/202 +++ b/tests/qemu-iotests/202 @@ -24,8 +24,7 @@ import iotests -iotests.verify_image_format(supported_fmts=['qcow2']) -iotests.verify_platform(['linux']) +iotests.script_initialize(supported_fmts=['qcow2']) with iotests.FilePath('disk0.img') as disk0_img_path, \ iotests.FilePath('disk1.img') as disk1_img_path, \ diff --git a/tests/qemu-iotests/203 b/tests/qemu-iotests/203 index 4874a1a0d8..c40fe231ea 100755 --- a/tests/qemu-iotests/203 +++ b/tests/qemu-iotests/203 @@ -24,8 +24,7 @@ import iotests -iotests.verify_image_format(supported_fmts=['qcow2']) -iotests.verify_platform(['linux']) +iotests.script_initialize(supported_fmts=['qcow2']) with iotests.FilePath('disk0.img') as disk0_img_path, \ iotests.FilePath('disk1.img') as disk1_img_path, \ diff --git a/tests/qemu-iotests/206 b/tests/qemu-iotests/206 index 5bb738bf23..23ff2f624b 100755 --- a/tests/qemu-iotests/206 +++ b/tests/qemu-iotests/206 @@ -23,7 +23,7 @@ import iotests from iotests import imgfmt -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) def blockdev_create(vm, options): result = vm.qmp_log('blockdev-create', diff --git a/tests/qemu-iotests/208 b/tests/qemu-iotests/208 index 1e202388dc..dfce6f9fe4 100755 --- a/tests/qemu-iotests/208 +++ b/tests/qemu-iotests/208 @@ -22,7 +22,7 @@ import iotests -iotests.verify_image_format(supported_fmts=['generic']) +iotests.script_initialize(supported_fmts=['generic']) with iotests.FilePath('disk.img') as disk_img_path, \ iotests.FilePath('disk-snapshot.img') as disk_snapshot_img_path, \ diff --git a/tests/qemu-iotests/216 b/tests/qemu-iotests/216 index 3c0ae54b44..7574bcc09f 100755 --- a/tests/qemu-iotests/216 +++ b/tests/qemu-iotests/216 @@ -23,8 +23,7 @@ import iotests from iotests import log, qemu_img, qemu_io_silent # Need backing file support -iotests.verify_image_format(supported_fmts=['qcow2', 'qcow', 'qed', 'vmdk']) -iotests.verify_platform(['linux']) +iotests.script_initialize(supported_fmts=['qcow2', 'qcow', 'qed', 'vmdk']) log('') log('=== Copy-on-read across nodes ===') diff --git a/tests/qemu-iotests/218 b/tests/qemu-iotests/218 index 2554d84581..e18e31076b 100755 --- a/tests/qemu-iotests/218 +++ b/tests/qemu-iotests/218 @@ -29,7 +29,7 @@ import iotests from iotests import log, qemu_img, qemu_io_silent -iotests.verify_image_format(supported_fmts=['qcow2', 'raw']) +iotests.script_initialize(supported_fmts=['qcow2', 'raw']) # Launches the VM, adds two null-co nodes (source and target), and diff --git a/tests/qemu-iotests/219 b/tests/qemu-iotests/219 index e0c51662c0..9ae27cb04e 100755 --- a/tests/qemu-iotests/219 +++ b/tests/qemu-iotests/219 @@ -21,7 +21,7 @@ import iotests -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) img_size = 4 * 1024 * 1024 diff --git a/tests/qemu-iotests/222 b/tests/qemu-iotests/222 index 0ead56d574..6788979ed3 100644 --- a/tests/qemu-iotests/222 +++ b/tests/qemu-iotests/222 @@ -24,9 +24,8 @@ import iotests from iotests import log, qemu_img, qemu_io, qemu_io_silent -iotests.verify_platform(['linux']) -iotests.verify_image_format(supported_fmts=['qcow2', 'qcow', 'qed', 'vmdk', - 'vhdx', 'raw']) +iotests.script_initialize(supported_fmts=['qcow2', 'qcow', 'qed', 'vmdk', + 'vhdx', 'raw']) patterns = [("0x5d", "0", "64k"), ("0xd5", "1M", "64k"), diff --git a/tests/qemu-iotests/224 b/tests/qemu-iotests/224 index b4dfaa639f..d0d0c44104 100755 --- a/tests/qemu-iotests/224 +++ b/tests/qemu-iotests/224 @@ -26,8 +26,7 @@ from iotests import log, qemu_img, qemu_io_silent, filter_qmp_testfiles, \ import json # Need backing file support (for arbitrary backing formats) -iotests.verify_image_format(supported_fmts=['qcow2', 'qcow', 'qed']) -iotests.verify_platform(['linux']) +iotests.script_initialize(supported_fmts=['qcow2', 'qcow', 'qed']) # There are two variations of this test: diff --git a/tests/qemu-iotests/228 b/tests/qemu-iotests/228 index 9a50afd205..9785868ab3 100755 --- a/tests/qemu-iotests/228 +++ b/tests/qemu-iotests/228 @@ -25,8 +25,7 @@ from iotests import log, qemu_img, filter_testfiles, filter_imgfmt, \ filter_qmp_testfiles, filter_qmp_imgfmt # Need backing file and change-backing-file support -iotests.verify_image_format(supported_fmts=['qcow2', 'qed']) -iotests.verify_platform(['linux']) +iotests.script_initialize(supported_fmts=['qcow2', 'qed']) def log_node_info(node): diff --git a/tests/qemu-iotests/234 b/tests/qemu-iotests/234 index c4c26bc21e..b72142040b 100755 --- a/tests/qemu-iotests/234 +++ b/tests/qemu-iotests/234 @@ -23,8 +23,7 @@ import iotests import os -iotests.verify_image_format(supported_fmts=['qcow2']) -iotests.verify_platform(['linux']) +iotests.script_initialize(supported_fmts=['qcow2']) def enable_migration_events(vm, name): iotests.log('Enabling migration QMP events on %s...' % name) diff --git a/tests/qemu-iotests/235 b/tests/qemu-iotests/235 index fedd111fd4..9e88c65b93 100755 --- a/tests/qemu-iotests/235 +++ b/tests/qemu-iotests/235 @@ -27,6 +27,8 @@ sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..', 'python')) from qemu.machine import QEMUMachine +iotests.script_initialize(supported_fmts=['qcow2']) + # Note: # This test was added to check that mirror dead-lock was fixed (see previous # commit before this test addition). @@ -40,8 +42,6 @@ from qemu.machine import QEMUMachine size = 1 * 1024 * 1024 * 1024 -iotests.verify_image_format(supported_fmts=['qcow2']) - disk = file_path('disk') # prepare source image diff --git a/tests/qemu-iotests/236 b/tests/qemu-iotests/236 index 79a6381f8e..b88779eb0b 100755 --- a/tests/qemu-iotests/236 +++ b/tests/qemu-iotests/236 @@ -22,7 +22,7 @@ import iotests from iotests import log -iotests.verify_image_format(supported_fmts=['generic']) +iotests.script_initialize(supported_fmts=['generic']) size = 64 * 1024 * 1024 granularity = 64 * 1024 diff --git a/tests/qemu-iotests/238 b/tests/qemu-iotests/238 index e5ac2b2ff8..6e27fb40c2 100755 --- a/tests/qemu-iotests/238 +++ b/tests/qemu-iotests/238 @@ -23,6 +23,8 @@ import os import iotests from iotests import log +iotests.script_initialize() + virtio_scsi_device = iotests.get_virtio_scsi_device() vm = iotests.VM() diff --git a/tests/qemu-iotests/242 b/tests/qemu-iotests/242 index c176e92da6..7c2685b4cc 100755 --- a/tests/qemu-iotests/242 +++ b/tests/qemu-iotests/242 @@ -24,7 +24,7 @@ import struct from iotests import qemu_img_create, qemu_io, qemu_img_pipe, \ file_path, img_info_log, log, filter_qemu_io -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) disk = file_path('disk') chunk = 256 * 1024 diff --git a/tests/qemu-iotests/246 b/tests/qemu-iotests/246 index b0997a392f..1d7747d62d 100755 --- a/tests/qemu-iotests/246 +++ b/tests/qemu-iotests/246 @@ -22,7 +22,7 @@ import iotests from iotests import log -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) size = 64 * 1024 * 1024 * 1024 gran_small = 32 * 1024 gran_large = 128 * 1024 diff --git a/tests/qemu-iotests/248 b/tests/qemu-iotests/248 index f26b4bb2aa..781b21b227 100755 --- a/tests/qemu-iotests/248 +++ b/tests/qemu-iotests/248 @@ -21,7 +21,7 @@ import iotests from iotests import qemu_img_create, qemu_io, file_path, filter_qmp_testfiles -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) source, target = file_path('source', 'target') size = 5 * 1024 * 1024 diff --git a/tests/qemu-iotests/254 b/tests/qemu-iotests/254 index 09584f3f7d..43b40f4f71 100755 --- a/tests/qemu-iotests/254 +++ b/tests/qemu-iotests/254 @@ -21,7 +21,7 @@ import iotests from iotests import qemu_img_create, file_path, log -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) disk, top = file_path('disk', 'top') size = 1024 * 1024 diff --git a/tests/qemu-iotests/255 b/tests/qemu-iotests/255 index 3632d507d0..ff16402268 100755 --- a/tests/qemu-iotests/255 +++ b/tests/qemu-iotests/255 @@ -23,7 +23,7 @@ import iotests from iotests import imgfmt -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) def blockdev_create(vm, options): result = vm.qmp_log('blockdev-create', diff --git a/tests/qemu-iotests/256 b/tests/qemu-iotests/256 index c594a43205..d2f9212e5a 100755 --- a/tests/qemu-iotests/256 +++ b/tests/qemu-iotests/256 @@ -23,7 +23,7 @@ import os import iotests from iotests import log -iotests.verify_image_format(supported_fmts=['qcow2']) +iotests.script_initialize(supported_fmts=['qcow2']) size = 64 * 1024 * 1024 with iotests.FilePath('img0') as img0_path, \ diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py index 727730422f..5e9b2989dd 100644 --- a/tests/qemu-iotests/iotests.py +++ b/tests/qemu-iotests/iotests.py @@ -891,9 +891,8 @@ def execute_unittest(output, verbosity, debug): sys.stderr.write(re.sub(r'Ran (\d+) tests? in [\d.]+s', r'Ran \1 tests', output.getvalue())) -def execute_test(test_function=None, - supported_fmts=[], supported_oses=['linux'], - supported_cache_modes=[], unsupported_fmts=[]): +def execute_setup_common(supported_fmts=[], supported_oses=['linux'], + supported_cache_modes=[], unsupported_fmts=[]): """Run either unittest or script-style tests.""" # We are using TEST_DIR and QEMU_DEFAULT_MACHINE as proxies to @@ -925,16 +924,28 @@ def execute_test(test_function=None, output = io.BytesIO() logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN)) + return output, verbosity, debug +def execute_test(test_function=None, *args, **kwargs): + """Run either unittest or script-style tests.""" + + unittest_args = execute_setup_common(*args, **kwargs) if not test_function: - execute_unittest(output, verbosity, debug) + execute_unittest(*unittest_args) else: test_function() +# This is called from script-style iotests without a single point of entry +def script_initialize(*args, **kwargs): + """Initialize script-style tests without running any tests.""" + execute_setup_common(*args, **kwargs) + +# This is called from script-style iotests with a single point of entry def script_main(test_function, *args, **kwargs): """Run script-style tests outside of the unittest framework""" execute_test(test_function, *args, **kwargs) +# This is called from unittest style iotests def main(*args, **kwargs): """Run tests using the unittest framework""" execute_test(None, *args, **kwargs) -- 2.21.0 ^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: [Qemu-devel] [PATCH 1/2] iotests: add script_initialize 2019-07-26 22:52 ` [Qemu-devel] [PATCH 1/2] iotests: add script_initialize John Snow @ 2019-07-29 0:07 ` Eduardo Habkost 2019-07-29 20:19 ` John Snow 0 siblings, 1 reply; 7+ messages in thread From: Eduardo Habkost @ 2019-07-29 0:07 UTC (permalink / raw) To: John Snow; +Cc: Kevin Wolf, qemu-devel, qemu-block, Max Reitz On Fri, Jul 26, 2019 at 06:52:00PM -0400, John Snow wrote: > Like script_main, but doesn't require a single point of entry. > Replace all existing initialization sections with this drop-in replacement. > > This brings debug support to all existing script-style iotests. > > Note: supported_oses=['linux'] was omitted, as it is a default argument. > Signed-off-by: John Snow <jsnow@redhat.com> [...] Looks good overall, I just have one comment: > diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py > index 727730422f..5e9b2989dd 100644 > --- a/tests/qemu-iotests/iotests.py > +++ b/tests/qemu-iotests/iotests.py > @@ -891,9 +891,8 @@ def execute_unittest(output, verbosity, debug): > sys.stderr.write(re.sub(r'Ran (\d+) tests? in [\d.]+s', > r'Ran \1 tests', output.getvalue())) > > -def execute_test(test_function=None, > - supported_fmts=[], supported_oses=['linux'], > - supported_cache_modes=[], unsupported_fmts=[]): > +def execute_setup_common(supported_fmts=[], supported_oses=['linux'], > + supported_cache_modes=[], unsupported_fmts=[]): > """Run either unittest or script-style tests.""" > > # We are using TEST_DIR and QEMU_DEFAULT_MACHINE as proxies to > @@ -925,16 +924,28 @@ def execute_test(test_function=None, > output = io.BytesIO() > > logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN)) > + return output, verbosity, debug Can't we make this simpler? What about just returning `debug`, and letting execute_unittest() take care of `verbosity` and `output`? > > +def execute_test(test_function=None, *args, **kwargs): > + """Run either unittest or script-style tests.""" > + > + unittest_args = execute_setup_common(*args, **kwargs) > if not test_function: > - execute_unittest(output, verbosity, debug) > + execute_unittest(*unittest_args) > else: > test_function() > > +# This is called from script-style iotests without a single point of entry > +def script_initialize(*args, **kwargs): > + """Initialize script-style tests without running any tests.""" > + execute_setup_common(*args, **kwargs) > + > +# This is called from script-style iotests with a single point of entry > def script_main(test_function, *args, **kwargs): > """Run script-style tests outside of the unittest framework""" > execute_test(test_function, *args, **kwargs) > > +# This is called from unittest style iotests > def main(*args, **kwargs): > """Run tests using the unittest framework""" > execute_test(None, *args, **kwargs) > -- > 2.21.0 > -- Eduardo ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [Qemu-devel] [PATCH 1/2] iotests: add script_initialize 2019-07-29 0:07 ` Eduardo Habkost @ 2019-07-29 20:19 ` John Snow 0 siblings, 0 replies; 7+ messages in thread From: John Snow @ 2019-07-29 20:19 UTC (permalink / raw) To: Eduardo Habkost; +Cc: Kevin Wolf, qemu-devel, qemu-block, Max Reitz On 7/28/19 8:07 PM, Eduardo Habkost wrote: > On Fri, Jul 26, 2019 at 06:52:00PM -0400, John Snow wrote: >> Like script_main, but doesn't require a single point of entry. >> Replace all existing initialization sections with this drop-in replacement. >> >> This brings debug support to all existing script-style iotests. >> >> Note: supported_oses=['linux'] was omitted, as it is a default argument. >> Signed-off-by: John Snow <jsnow@redhat.com> > [...] > > Looks good overall, I just have one comment: > > >> diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py >> index 727730422f..5e9b2989dd 100644 >> --- a/tests/qemu-iotests/iotests.py >> +++ b/tests/qemu-iotests/iotests.py >> @@ -891,9 +891,8 @@ def execute_unittest(output, verbosity, debug): >> sys.stderr.write(re.sub(r'Ran (\d+) tests? in [\d.]+s', >> r'Ran \1 tests', output.getvalue())) >> >> -def execute_test(test_function=None, >> - supported_fmts=[], supported_oses=['linux'], >> - supported_cache_modes=[], unsupported_fmts=[]): >> +def execute_setup_common(supported_fmts=[], supported_oses=['linux'], >> + supported_cache_modes=[], unsupported_fmts=[]): >> """Run either unittest or script-style tests.""" >> >> # We are using TEST_DIR and QEMU_DEFAULT_MACHINE as proxies to >> @@ -925,16 +924,28 @@ def execute_test(test_function=None, >> output = io.BytesIO() >> >> logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN)) >> + return output, verbosity, debug > > Can't we make this simpler? > > What about just returning `debug`, and letting execute_unittest() > take care of `verbosity` and `output`? > "yes," it turns out. v2 soon. ^ permalink raw reply [flat|nested] 7+ messages in thread
* [Qemu-devel] [PATCH 2/2] iotests: use python logging for iotests.log() 2019-07-26 22:51 [Qemu-devel] [PATCH 0/2] iotests: use python logging John Snow 2019-07-26 22:52 ` [Qemu-devel] [PATCH 1/2] iotests: add script_initialize John Snow @ 2019-07-26 22:52 ` John Snow 2019-07-28 23:36 ` Eduardo Habkost 1 sibling, 1 reply; 7+ messages in thread From: John Snow @ 2019-07-26 22:52 UTC (permalink / raw) To: qemu-devel, qemu-block; +Cc: Kevin Wolf, John Snow, ehabkost, Max Reitz We can turn logging on/off globally instead of per-function. Remove use_log from run_job, and use python logging to turn on diffable output when we run through a script entry point. (No, I have no idea why output on 245 changed. I really don't.) Signed-off-by: John Snow <jsnow@redhat.com> --- tests/qemu-iotests/030 | 4 +-- tests/qemu-iotests/245 | 1 + tests/qemu-iotests/245.out | 24 +++++++++--------- tests/qemu-iotests/iotests.py | 48 ++++++++++++++++++++--------------- 4 files changed, 43 insertions(+), 34 deletions(-) diff --git a/tests/qemu-iotests/030 b/tests/qemu-iotests/030 index 1b69f318c6..a382cb430b 100755 --- a/tests/qemu-iotests/030 +++ b/tests/qemu-iotests/030 @@ -411,8 +411,8 @@ class TestParallelOps(iotests.QMPTestCase): result = self.vm.qmp('block-job-set-speed', device='drive0', speed=0) self.assert_qmp(result, 'return', {}) - self.vm.run_job(job='drive0', auto_dismiss=True, use_log=False) - self.vm.run_job(job='node4', auto_dismiss=True, use_log=False) + self.vm.run_job(job='drive0', auto_dismiss=True) + self.vm.run_job(job='node4', auto_dismiss=True) self.assert_no_active_block_jobs() # Test a block-stream and a block-commit job in parallel diff --git a/tests/qemu-iotests/245 b/tests/qemu-iotests/245 index bc1ceb9792..3bc29acb33 100644 --- a/tests/qemu-iotests/245 +++ b/tests/qemu-iotests/245 @@ -1000,4 +1000,5 @@ class TestBlockdevReopen(iotests.QMPTestCase): self.reopen(opts, {'backing': 'hd2'}) if __name__ == '__main__': + iotests.activate_logging() iotests.main(supported_fmts=["qcow2"]) diff --git a/tests/qemu-iotests/245.out b/tests/qemu-iotests/245.out index a19de5214d..15c3630e92 100644 --- a/tests/qemu-iotests/245.out +++ b/tests/qemu-iotests/245.out @@ -1,17 +1,17 @@ +{"execute": "job-finalize", "arguments": {"id": "commit0"}} +{"return": {}} +{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +{"execute": "job-finalize", "arguments": {"id": "stream0"}} +{"return": {}} +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +{"execute": "job-finalize", "arguments": {"id": "stream0"}} +{"return": {}} +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} .................. ---------------------------------------------------------------------- Ran 18 tests OK -{"execute": "job-finalize", "arguments": {"id": "commit0"}} -{"return": {}} -{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} -{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} -{"execute": "job-finalize", "arguments": {"id": "stream0"}} -{"return": {}} -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} -{"execute": "job-finalize", "arguments": {"id": "stream0"}} -{"return": {}} -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py index 5e9b2989dd..d55ca864eb 100644 --- a/tests/qemu-iotests/iotests.py +++ b/tests/qemu-iotests/iotests.py @@ -35,6 +35,13 @@ from collections import OrderedDict sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..', 'python')) from qemu import qtest +# Use this logger for logging messages directly from the iotests module +logger = logging.getLogger(__name__) +logger.addHandler(logging.NullHandler()) + +# Use this logger for messages that ought to be used for diff output. +test_logger = logging.getLogger('.'.join((__name__, 'iotest'))) +test_logger.addHandler(logging.NullHandler()) # This will not work if arguments contain spaces but is necessary if we # want to support the override options that ./check supports. @@ -343,10 +350,10 @@ def log(msg, filters=[], indent=None): separators = (', ', ': ') if indent is None else (',', ': ') # Don't sort if it's already sorted do_sort = not isinstance(msg, OrderedDict) - print(json.dumps(msg, sort_keys=do_sort, - indent=indent, separators=separators)) + test_logger.info(json.dumps(msg, sort_keys=do_sort, + indent=indent, separators=separators)) else: - print(msg) + test_logger.info(msg) class Timeout: def __init__(self, seconds, errmsg = "Timeout"): @@ -559,7 +566,7 @@ class VM(qtest.QEMUQtestMachine): # Returns None on success, and an error string on failure def run_job(self, job, auto_finalize=True, auto_dismiss=False, - pre_finalize=None, cancel=False, use_log=True, wait=60.0): + pre_finalize=None, cancel=False, wait=60.0): """ run_job moves a job from creation through to dismissal. @@ -572,7 +579,6 @@ class VM(qtest.QEMUQtestMachine): invoked prior to issuing job-finalize, if any. :param cancel: Bool. When true, cancels the job after the pre_finalize callback. - :param use_log: Bool. When false, does not log QMP messages. :param wait: Float. Timeout value specifying how long to wait for any event, in seconds. Defaults to 60.0. """ @@ -590,8 +596,7 @@ class VM(qtest.QEMUQtestMachine): while True: ev = filter_qmp_event(self.events_wait(events)) if ev['event'] != 'JOB_STATUS_CHANGE': - if use_log: - log(ev) + log(ev) continue status = ev['data']['status'] if status == 'aborting': @@ -599,24 +604,15 @@ class VM(qtest.QEMUQtestMachine): for j in result['return']: if j['id'] == job: error = j['error'] - if use_log: - log('Job failed: %s' % (j['error'])) + log('Job failed: %s' % (j['error'])) elif status == 'pending' and not auto_finalize: if pre_finalize: pre_finalize() - if cancel and use_log: + if cancel: self.qmp_log('job-cancel', id=job) - elif cancel: - self.qmp('job-cancel', id=job) - if use_log: - self.qmp_log('job-finalize', id=job) - else: - self.qmp('job-finalize', id=job) + self.qmp_log('job-finalize', id=job) elif status == 'concluded' and not auto_dismiss: - if use_log: - self.qmp_log('job-dismiss', id=job) - else: - self.qmp('job-dismiss', id=job) + self.qmp_log('job-dismiss', id=job) elif status == 'null': return error @@ -924,6 +920,7 @@ def execute_setup_common(supported_fmts=[], supported_oses=['linux'], output = io.BytesIO() logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN)) + logger.debug("iotests debugging messages active") return output, verbosity, debug def execute_test(test_function=None, *args, **kwargs): @@ -935,14 +932,25 @@ def execute_test(test_function=None, *args, **kwargs): else: test_function() +def activate_logging(): + """Activate iotests.log() output to stdout for script-style tests.""" + handler = logging.StreamHandler(stream=sys.stdout) + formatter = logging.Formatter('%(message)s') + handler.setFormatter(formatter) + test_logger.addHandler(handler) + test_logger.setLevel(logging.INFO) + test_logger.propagate = False + # This is called from script-style iotests without a single point of entry def script_initialize(*args, **kwargs): """Initialize script-style tests without running any tests.""" + activate_logging() execute_setup_common(*args, **kwargs) # This is called from script-style iotests with a single point of entry def script_main(test_function, *args, **kwargs): """Run script-style tests outside of the unittest framework""" + activate_logging() execute_test(test_function, *args, **kwargs) # This is called from unittest style iotests -- 2.21.0 ^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: [Qemu-devel] [PATCH 2/2] iotests: use python logging for iotests.log() 2019-07-26 22:52 ` [Qemu-devel] [PATCH 2/2] iotests: use python logging for iotests.log() John Snow @ 2019-07-28 23:36 ` Eduardo Habkost 2019-07-29 15:43 ` John Snow 0 siblings, 1 reply; 7+ messages in thread From: Eduardo Habkost @ 2019-07-28 23:36 UTC (permalink / raw) To: John Snow; +Cc: Kevin Wolf, qemu-devel, qemu-block, Max Reitz On Fri, Jul 26, 2019 at 06:52:01PM -0400, John Snow wrote: > We can turn logging on/off globally instead of per-function. > > Remove use_log from run_job, and use python logging to turn on > diffable output when we run through a script entry point. > > (No, I have no idea why output on 245 changed. I really don't.) I believe this happens because the logging StreamHandler will flush the stream at every call. I see the same output reordering on 245 if I add a sys.stdout.flush() call to iotests.log(), or if I change iotests.main() to use sys.stdout for the unittest runner output. > > Signed-off-by: John Snow <jsnow@redhat.com> > --- > tests/qemu-iotests/030 | 4 +-- > tests/qemu-iotests/245 | 1 + > tests/qemu-iotests/245.out | 24 +++++++++--------- > tests/qemu-iotests/iotests.py | 48 ++++++++++++++++++++--------------- > 4 files changed, 43 insertions(+), 34 deletions(-) > > diff --git a/tests/qemu-iotests/030 b/tests/qemu-iotests/030 > index 1b69f318c6..a382cb430b 100755 > --- a/tests/qemu-iotests/030 > +++ b/tests/qemu-iotests/030 > @@ -411,8 +411,8 @@ class TestParallelOps(iotests.QMPTestCase): > result = self.vm.qmp('block-job-set-speed', device='drive0', speed=0) > self.assert_qmp(result, 'return', {}) > > - self.vm.run_job(job='drive0', auto_dismiss=True, use_log=False) > - self.vm.run_job(job='node4', auto_dismiss=True, use_log=False) > + self.vm.run_job(job='drive0', auto_dismiss=True) > + self.vm.run_job(job='node4', auto_dismiss=True) So, this one is the only run_job() caller specifying use_log=False. It doesn't call activate_logging() anywhere, so it seems OK. However, we need to ensure all the other run_job() callers will actually enable logging. The remaining run_job() callers are: 206 207 210 211 212 213 237 245 255 256. These look OK: 206:iotests.script_initialize(supported_fmts=['qcow2']) 245: iotests.activate_logging() 255:iotests.script_initialize(supported_fmts=['qcow2']) 256:iotests.script_initialize(supported_fmts=['qcow2']) 257: iotests.script_main(main, supported_fmts=['qcow2']) These don't seem to call activate_logging() anywhere: 207 210 211 212 213 237. What about other scripts calling log() that aren't calling activate_logging()? Let's see: $ git grep -LE 'script_main|script_initialize|activate_logging' \ $(grep -lP '(?<!get_)log\(' [0-9]*) 207 210 211 212 213 237 $ I didn't run all of these test cases, but I can see that 210 is now failing: $ ./check -luks 210 QEMU -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../x86_64-softmmu/qemu-system-x86_64" -nodefaults -machine accel=qtest QEMU_IMG -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../qemu-img" QEMU_IO -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../qemu-io" --cache writeback QEMU_NBD -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../qemu-nbd" IMGFMT -- luks (iter-time=10) IMGPROTO -- file TEST_DIR -- /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/scratch SOCKET_SCM_HELPER -- /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/socket_scm_helper 210 fail [20:20:37] [20:21:00] (last: 22s) output mismatch (see 210.out.bad) --- /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/210.out 2019-07-28 18:38:18.040555415 -0300 +++ /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/210.out.bad 2019-07-28 20:20:37.398971280 -0300 @@ -1,231 +0,0 @@ -=== Successful image creation (defaults) === - -{"execute": "blockdev-create", "arguments": {"job-id": "job0", "options": {"driver": "file", "filename": "TEST_DIR/PID-t.luks", "size": 0}}} [...] As most test cases require logging to be enabled, my suggestion is to activate logging by default and provide a disable_test_logging() function that can be used by 030. > self.assert_no_active_block_jobs() > > # Test a block-stream and a block-commit job in parallel > diff --git a/tests/qemu-iotests/245 b/tests/qemu-iotests/245 > index bc1ceb9792..3bc29acb33 100644 > --- a/tests/qemu-iotests/245 > +++ b/tests/qemu-iotests/245 > @@ -1000,4 +1000,5 @@ class TestBlockdevReopen(iotests.QMPTestCase): > self.reopen(opts, {'backing': 'hd2'}) > > if __name__ == '__main__': > + iotests.activate_logging() > iotests.main(supported_fmts=["qcow2"]) > diff --git a/tests/qemu-iotests/245.out b/tests/qemu-iotests/245.out > index a19de5214d..15c3630e92 100644 > --- a/tests/qemu-iotests/245.out > +++ b/tests/qemu-iotests/245.out > @@ -1,17 +1,17 @@ > +{"execute": "job-finalize", "arguments": {"id": "commit0"}} > +{"return": {}} > +{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > +{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > +{"execute": "job-finalize", "arguments": {"id": "stream0"}} > +{"return": {}} > +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > +{"execute": "job-finalize", "arguments": {"id": "stream0"}} > +{"return": {}} > +{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > +{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > .................. > ---------------------------------------------------------------------- > Ran 18 tests > > OK > -{"execute": "job-finalize", "arguments": {"id": "commit0"}} > -{"return": {}} > -{"data": {"id": "commit0", "type": "commit"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > -{"data": {"device": "commit0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "commit"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > -{"execute": "job-finalize", "arguments": {"id": "stream0"}} > -{"return": {}} > -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > -{"execute": "job-finalize", "arguments": {"id": "stream0"}} > -{"return": {}} > -{"data": {"id": "stream0", "type": "stream"}, "event": "BLOCK_JOB_PENDING", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > -{"data": {"device": "stream0", "len": 3145728, "offset": 3145728, "speed": 0, "type": "stream"}, "event": "BLOCK_JOB_COMPLETED", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}} > diff --git a/tests/qemu-iotests/iotests.py b/tests/qemu-iotests/iotests.py > index 5e9b2989dd..d55ca864eb 100644 > --- a/tests/qemu-iotests/iotests.py > +++ b/tests/qemu-iotests/iotests.py > @@ -35,6 +35,13 @@ from collections import OrderedDict > sys.path.append(os.path.join(os.path.dirname(__file__), '..', '..', 'python')) > from qemu import qtest > > +# Use this logger for logging messages directly from the iotests module > +logger = logging.getLogger(__name__) > +logger.addHandler(logging.NullHandler()) > + > +# Use this logger for messages that ought to be used for diff output. > +test_logger = logging.getLogger('.'.join((__name__, 'iotest'))) > +test_logger.addHandler(logging.NullHandler()) > > # This will not work if arguments contain spaces but is necessary if we > # want to support the override options that ./check supports. > @@ -343,10 +350,10 @@ def log(msg, filters=[], indent=None): > separators = (', ', ': ') if indent is None else (',', ': ') > # Don't sort if it's already sorted > do_sort = not isinstance(msg, OrderedDict) > - print(json.dumps(msg, sort_keys=do_sort, > - indent=indent, separators=separators)) > + test_logger.info(json.dumps(msg, sort_keys=do_sort, > + indent=indent, separators=separators)) > else: > - print(msg) > + test_logger.info(msg) > > class Timeout: > def __init__(self, seconds, errmsg = "Timeout"): > @@ -559,7 +566,7 @@ class VM(qtest.QEMUQtestMachine): > > # Returns None on success, and an error string on failure > def run_job(self, job, auto_finalize=True, auto_dismiss=False, > - pre_finalize=None, cancel=False, use_log=True, wait=60.0): > + pre_finalize=None, cancel=False, wait=60.0): > """ > run_job moves a job from creation through to dismissal. > > @@ -572,7 +579,6 @@ class VM(qtest.QEMUQtestMachine): > invoked prior to issuing job-finalize, if any. > :param cancel: Bool. When true, cancels the job after the pre_finalize > callback. > - :param use_log: Bool. When false, does not log QMP messages. > :param wait: Float. Timeout value specifying how long to wait for any > event, in seconds. Defaults to 60.0. > """ > @@ -590,8 +596,7 @@ class VM(qtest.QEMUQtestMachine): > while True: > ev = filter_qmp_event(self.events_wait(events)) > if ev['event'] != 'JOB_STATUS_CHANGE': > - if use_log: > - log(ev) > + log(ev) > continue > status = ev['data']['status'] > if status == 'aborting': > @@ -599,24 +604,15 @@ class VM(qtest.QEMUQtestMachine): > for j in result['return']: > if j['id'] == job: > error = j['error'] > - if use_log: > - log('Job failed: %s' % (j['error'])) > + log('Job failed: %s' % (j['error'])) > elif status == 'pending' and not auto_finalize: > if pre_finalize: > pre_finalize() > - if cancel and use_log: > + if cancel: > self.qmp_log('job-cancel', id=job) > - elif cancel: > - self.qmp('job-cancel', id=job) > - if use_log: > - self.qmp_log('job-finalize', id=job) > - else: > - self.qmp('job-finalize', id=job) > + self.qmp_log('job-finalize', id=job) > elif status == 'concluded' and not auto_dismiss: > - if use_log: > - self.qmp_log('job-dismiss', id=job) > - else: > - self.qmp('job-dismiss', id=job) > + self.qmp_log('job-dismiss', id=job) > elif status == 'null': > return error > > @@ -924,6 +920,7 @@ def execute_setup_common(supported_fmts=[], supported_oses=['linux'], > output = io.BytesIO() > > logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN)) > + logger.debug("iotests debugging messages active") > return output, verbosity, debug > > def execute_test(test_function=None, *args, **kwargs): > @@ -935,14 +932,25 @@ def execute_test(test_function=None, *args, **kwargs): > else: > test_function() > > +def activate_logging(): > + """Activate iotests.log() output to stdout for script-style tests.""" > + handler = logging.StreamHandler(stream=sys.stdout) > + formatter = logging.Formatter('%(message)s') > + handler.setFormatter(formatter) > + test_logger.addHandler(handler) > + test_logger.setLevel(logging.INFO) > + test_logger.propagate = False > + > # This is called from script-style iotests without a single point of entry > def script_initialize(*args, **kwargs): > """Initialize script-style tests without running any tests.""" > + activate_logging() > execute_setup_common(*args, **kwargs) > > # This is called from script-style iotests with a single point of entry > def script_main(test_function, *args, **kwargs): > """Run script-style tests outside of the unittest framework""" > + activate_logging() > execute_test(test_function, *args, **kwargs) > > # This is called from unittest style iotests > -- > 2.21.0 > -- Eduardo ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [Qemu-devel] [PATCH 2/2] iotests: use python logging for iotests.log() 2019-07-28 23:36 ` Eduardo Habkost @ 2019-07-29 15:43 ` John Snow 0 siblings, 0 replies; 7+ messages in thread From: John Snow @ 2019-07-29 15:43 UTC (permalink / raw) To: Eduardo Habkost; +Cc: Kevin Wolf, qemu-devel, qemu-block, Max Reitz On 7/28/19 7:36 PM, Eduardo Habkost wrote: > On Fri, Jul 26, 2019 at 06:52:01PM -0400, John Snow wrote: >> We can turn logging on/off globally instead of per-function. >> >> Remove use_log from run_job, and use python logging to turn on >> diffable output when we run through a script entry point. >> >> (No, I have no idea why output on 245 changed. I really don't.) > > I believe this happens because the logging StreamHandler will > flush the stream at every call. > I'm surprised print doesn't flush that often. > I see the same output reordering on 245 if I add a > sys.stdout.flush() call to iotests.log(), or if I change > iotests.main() to use sys.stdout for the unittest runner output. > >> >> Signed-off-by: John Snow <jsnow@redhat.com> >> --- >> tests/qemu-iotests/030 | 4 +-- >> tests/qemu-iotests/245 | 1 + >> tests/qemu-iotests/245.out | 24 +++++++++--------- >> tests/qemu-iotests/iotests.py | 48 ++++++++++++++++++++--------------- >> 4 files changed, 43 insertions(+), 34 deletions(-) >> >> diff --git a/tests/qemu-iotests/030 b/tests/qemu-iotests/030 >> index 1b69f318c6..a382cb430b 100755 >> --- a/tests/qemu-iotests/030 >> +++ b/tests/qemu-iotests/030 >> @@ -411,8 +411,8 @@ class TestParallelOps(iotests.QMPTestCase): >> result = self.vm.qmp('block-job-set-speed', device='drive0', speed=0) >> self.assert_qmp(result, 'return', {}) >> >> - self.vm.run_job(job='drive0', auto_dismiss=True, use_log=False) >> - self.vm.run_job(job='node4', auto_dismiss=True, use_log=False) >> + self.vm.run_job(job='drive0', auto_dismiss=True) >> + self.vm.run_job(job='node4', auto_dismiss=True) > > So, this one is the only run_job() caller specifying > use_log=False. It doesn't call activate_logging() anywhere, so > it seems OK. > Yah > However, we need to ensure all the other run_job() callers will > actually enable logging. The remaining run_job() callers are: > 206 207 210 211 212 213 237 245 255 256. > > These look OK: > 206:iotests.script_initialize(supported_fmts=['qcow2']) > 245: iotests.activate_logging() > 255:iotests.script_initialize(supported_fmts=['qcow2']) > 256:iotests.script_initialize(supported_fmts=['qcow2']) > 257: iotests.script_main(main, supported_fmts=['qcow2']) > > These don't seem to call activate_logging() anywhere: > 207 210 211 212 213 237. > There's the quick hack -- not verifying all the non-qcow tests as per usual. All of these are script-style and should call to script_initialize now instead. Fixed! > What about other scripts calling log() that aren't calling activate_logging()? > Let's see: > > $ git grep -LE 'script_main|script_initialize|activate_logging' \ > $(grep -lP '(?<!get_)log\(' [0-9]*) > 207 > 210 > 211 > 212 > 213 > 237 > $ > > > I didn't run all of these test cases, but I can see that 210 is > now failing: > > $ ./check -luks 210 > QEMU -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../x86_64-softmmu/qemu-system-x86_64" -nodefaults -machine accel=qtest > QEMU_IMG -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../qemu-img" > QEMU_IO -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../qemu-io" --cache writeback > QEMU_NBD -- "/home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/../../qemu-nbd" > IMGFMT -- luks (iter-time=10) > IMGPROTO -- file > > TEST_DIR -- /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/scratch > SOCKET_SCM_HELPER -- /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/socket_scm_helper > > 210 fail [20:20:37] [20:21:00] (last: 22s) output mismatch (see 210.out.bad) > --- /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/210.out 2019-07-28 18:38:18.040555415 -0300 > +++ /home/ehabkost/rh/proj/virt/qemu/tests/qemu-iotests/210.out.bad 2019-07-28 20:20:37.398971280 -0300 > @@ -1,231 +0,0 @@ > -=== Successful image creation (defaults) === > - > -{"execute": "blockdev-create", "arguments": {"job-id": "job0", "options": {"driver": "file", "filename": "TEST_DIR/PID-t.luks", "size": 0}}} > [...] > > > As most test cases require logging to be enabled, my suggestion > is to activate logging by default and provide a > disable_test_logging() function that can be used by 030. > Actually, we'd need to disable logging for all the unittest style tests, so it's probably a wash as to whether we do enable-or-disable by default. I think disable-by-default has the benefit of making it obvious when you're missing a call to script_initialize, so I'd like to go that route. So basically you have: A) Unittest - disabled by default B) script-style - enabled by default You only need to override this layout for one case -- test 245 -- which was written to expect run_job logging, which I did in this patch. I'll send a V2 that mocks this up. --js ^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2019-07-29 20:19 UTC | newest] Thread overview: 7+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2019-07-26 22:51 [Qemu-devel] [PATCH 0/2] iotests: use python logging John Snow 2019-07-26 22:52 ` [Qemu-devel] [PATCH 1/2] iotests: add script_initialize John Snow 2019-07-29 0:07 ` Eduardo Habkost 2019-07-29 20:19 ` John Snow 2019-07-26 22:52 ` [Qemu-devel] [PATCH 2/2] iotests: use python logging for iotests.log() John Snow 2019-07-28 23:36 ` Eduardo Habkost 2019-07-29 15:43 ` John Snow
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).