Some tests are creating their on logger category which means any
output they log is not captured in base.log.
Signed-off-by: Daniel P. Berrangé <berra...@redhat.com>
---
tests/functional/aarch64/test_virt.py | 4 +--
tests/functional/arm/test_integratorcp.py | 3 +-
tests/functional/mips64el/test_malta.py | 3 +-
tests/functional/replay_kernel.py | 16 ++++-----
tests/functional/reverse_debugging.py | 41 +++++++++++------------
tests/functional/x86_64/test_acpi_bits.py | 31 +++++++++--------
6 files changed, 44 insertions(+), 54 deletions(-)
diff --git a/tests/functional/aarch64/test_virt.py
b/tests/functional/aarch64/test_virt.py
index 4d0ad90ff8..63071f9b51 100755
--- a/tests/functional/aarch64/test_virt.py
+++ b/tests/functional/aarch64/test_virt.py
@@ -72,8 +72,6 @@ def common_aarch64_virt(self, machine):
self.set_machine('virt')
self.require_accelerator("tcg")
- logger = logging.getLogger('aarch64_virt')
-
kernel_path = self.ASSET_KERNEL.fetch()
self.vm.set_console()
@@ -91,7 +89,7 @@ def common_aarch64_virt(self, machine):
'rng-random,id=rng0,filename=/dev/urandom')
# Also add a scratch block device
- logger.info('creating scratch qcow2 image')
+ self.log.info('creating scratch qcow2 image')
image_path = self.scratch_file('scratch.qcow2')
qemu_img = get_qemu_img(self)
check_call([qemu_img, 'create', '-f', 'qcow2', image_path, '8M'],
diff --git a/tests/functional/arm/test_integratorcp.py
b/tests/functional/arm/test_integratorcp.py
index 4f00924aa0..23ae919359 100755
--- a/tests/functional/arm/test_integratorcp.py
+++ b/tests/functional/arm/test_integratorcp.py
@@ -77,7 +77,6 @@ def test_framebuffer_tux_logo(self):
command_line='screendump %s' % screendump_path)
if 'unknown command' in res:
self.skipTest('screendump not available')
- logger = logging.getLogger('framebuffer')
cpu_count = 1
match_threshold = 0.92
@@ -88,7 +87,7 @@ def test_framebuffer_tux_logo(self):
loc = np.where(result >= match_threshold)
tux_count = 0
for tux_count, pt in enumerate(zip(*loc[::-1]), start=1):
- logger.debug('found Tux at position [x, y] = %s', pt)
+ self.log.debug('found Tux at position [x, y] = %s', pt)
self.assertGreaterEqual(tux_count, cpu_count)
if __name__ == '__main__':
diff --git a/tests/functional/mips64el/test_malta.py
b/tests/functional/mips64el/test_malta.py
index 8fdc49b300..170147bfcc 100755
--- a/tests/functional/mips64el/test_malta.py
+++ b/tests/functional/mips64el/test_malta.py
@@ -159,7 +159,6 @@ def do_test_i6400_framebuffer_logo(self, cpu_cores_count):
command_line='screendump %s' % screendump_path)
if 'unknown command' in res:
self.skipTest('screendump not available')
- logger = logging.getLogger('framebuffer')
match_threshold = 0.95
screendump_bgr = cv2.imread(screendump_path, cv2.IMREAD_COLOR)
@@ -171,7 +170,7 @@ def do_test_i6400_framebuffer_logo(self, cpu_cores_count):
h, w = tuxlogo_bgr.shape[:2]
debug_png = os.getenv('QEMU_TEST_CV2_SCREENDUMP_PNG_PATH')
for tuxlogo_count, pt in enumerate(zip(*loc[::-1]), start=1):
- logger.debug('found Tux at position (x, y) = %s', pt)
+ self.log.debug('found Tux at position (x, y) = %s', pt)
cv2.rectangle(screendump_bgr, pt,
(pt[0] + w, pt[1] + h), (0, 0, 255), 2)
if debug_png:
diff --git a/tests/functional/replay_kernel.py
b/tests/functional/replay_kernel.py
index 80795eb052..acb1d29a1b 100644
--- a/tests/functional/replay_kernel.py
+++ b/tests/functional/replay_kernel.py
@@ -32,15 +32,14 @@ def run_vm(self, kernel_path, kernel_command_line,
console_pattern,
# icount requires TCG to be available
self.require_accelerator('tcg')
- logger = logging.getLogger('replay')
start_time = time.time()
vm = self.get_vm(name='recording' if record else 'replay')
vm.set_console()
if record:
- logger.info('recording the execution...')
+ self.log.info('recording the execution...')
mode = 'record'
else:
- logger.info('replaying the execution...')
+ self.log.info('replaying the execution...')
mode = 'replay'
vm.add_args('-icount', 'shift=%s,rr=%s,rrfile=%s' %
(shift, mode, replay_path),
@@ -54,15 +53,15 @@ def run_vm(self, kernel_path, kernel_command_line,
console_pattern,
self.wait_for_console_pattern(console_pattern, vm)
if record:
vm.shutdown()
- logger.info('finished the recording with log size %s bytes'
+ self.log.info('finished the recording with log size %s bytes'
% os.path.getsize(replay_path))
self.run_replay_dump(replay_path)
- logger.info('successfully tested replay-dump.py')
+ self.log.info('successfully tested replay-dump.py')
else:
vm.wait()
- logger.info('successfully finished the replay')
+ self.log.info('successfully finished the replay')
elapsed = time.time() - start_time
- logger.info('elapsed time %.2f sec' % elapsed)
+ self.log.info('elapsed time %.2f sec' % elapsed)
return elapsed
def run_replay_dump(self, replay_path):
@@ -80,5 +79,4 @@ def run_rr(self, kernel_path, kernel_command_line,
console_pattern,
True, shift, args, replay_path)
t2 = self.run_vm(kernel_path, kernel_command_line, console_pattern,
False, shift, args, replay_path)
- logger = logging.getLogger('replay')
- logger.info('replay overhead {:.2%}'.format(t2 / t1 - 1))
+ self.log.info('replay overhead {:.2%}'.format(t2 / t1 - 1))
diff --git a/tests/functional/reverse_debugging.py
b/tests/functional/reverse_debugging.py
index fbb5adbcce..be5d70f97f 100644
--- a/tests/functional/reverse_debugging.py
+++ b/tests/functional/reverse_debugging.py
@@ -35,14 +35,13 @@ class ReverseDebugging(LinuxKernelTest):
endian_is_le = True
def run_vm(self, record, shift, args, replay_path, image_path, port):
- logger = logging.getLogger('replay')
vm = self.get_vm(name='record' if record else 'replay')
vm.set_console()
if record:
- logger.info('recording the execution...')
+ self.log.info('recording the execution...')
mode = 'record'
else:
- logger.info('replaying the execution...')
+ self.log.info('replaying the execution...')
mode = 'replay'
vm.add_args('-gdb', 'tcp::%d' % port, '-S')
vm.add_args('-icount', 'shift=%s,rr=%s,rrfile=%s,rrsnapshot=init' %
@@ -95,10 +94,8 @@ def vm_get_icount(vm):
return vm.qmp('query-replay')['return']['icount']
def reverse_debugging(self, shift=7, args=None):
- logger = logging.getLogger('replay')
-
# create qcow2 for snapshots
- logger.info('creating qcow2 image for VM snapshots')
+ self.log.info('creating qcow2 image for VM snapshots')
image_path = os.path.join(self.workdir, 'disk.qcow2')
qemu_img = get_qemu_img(self)
if qemu_img is None:
@@ -106,7 +103,7 @@ def reverse_debugging(self, shift=7, args=None):
'create the temporary qcow2 image')
out = check_output([qemu_img, 'create', '-f', 'qcow2', image_path,
'128M'],
encoding='utf8')
- logger.info("qemu-img: %s" % out)
+ self.log.info("qemu-img: %s" % out)
replay_path = os.path.join(self.workdir, 'replay.bin')
@@ -117,13 +114,13 @@ def reverse_debugging(self, shift=7, args=None):
last_icount = self.vm_get_icount(vm)
vm.shutdown()
- logger.info("recorded log with %s+ steps" % last_icount)
+ self.log.info("recorded log with %s+ steps" % last_icount)
# replay and run debug commands
with Ports() as ports:
port = ports.find_free_port()
vm = self.run_vm(False, shift, args, replay_path, image_path, port)
- logger.info('connecting to gdbstub')
+ self.log.info('connecting to gdbstub')
g = GDBRemote('127.0.0.1', port, False, False)
g.connect()
r = g.cmd(b'qSupported')
@@ -134,59 +131,59 @@ def reverse_debugging(self, shift=7, args=None):
if b'ReverseContinue+' not in r:
self.fail('Reverse continue is not supported by QEMU')
- logger.info('stepping forward')
+ self.log.info('stepping forward')
steps = []
# record first instruction addresses
for _ in range(self.STEPS):
pc = self.get_pc(g)
- logger.info('saving position %x' % pc)
+ self.log.info('saving position %x' % pc)
steps.append(pc)
self.gdb_step(g)
# visit the recorded instruction in reverse order
- logger.info('stepping backward')
+ self.log.info('stepping backward')
for addr in steps[::-1]:
self.gdb_bstep(g)
self.check_pc(g, addr)
- logger.info('found position %x' % addr)
+ self.log.info('found position %x' % addr)
# visit the recorded instruction in forward order
- logger.info('stepping forward')
+ self.log.info('stepping forward')
for addr in steps:
self.check_pc(g, addr)
self.gdb_step(g)
- logger.info('found position %x' % addr)
+ self.log.info('found position %x' % addr)
# set breakpoints for the instructions just stepped over
- logger.info('setting breakpoints')
+ self.log.info('setting breakpoints')
for addr in steps:
# hardware breakpoint at addr with len=1
g.cmd(b'Z1,%x,1' % addr, b'OK')
# this may hit a breakpoint if first instructions are executed
# again
- logger.info('continuing execution')
+ self.log.info('continuing execution')
vm.qmp('replay-break', icount=last_icount - 1)
# continue - will return after pausing
# This could stop at the end and get a T02 return, or by
# re-executing one of the breakpoints and get a T05 return.
g.cmd(b'c')
if self.vm_get_icount(vm) == last_icount - 1:
- logger.info('reached the end (icount %s)' % (last_icount - 1))
+ self.log.info('reached the end (icount %s)' % (last_icount - 1))
else:
- logger.info('hit a breakpoint again at %x (icount %s)' %
+ self.log.info('hit a breakpoint again at %x (icount %s)' %
(self.get_pc(g), self.vm_get_icount(vm)))
- logger.info('running reverse continue to reach %x' % steps[-1])
+ self.log.info('running reverse continue to reach %x' % steps[-1])
# reverse continue - will return after stopping at the breakpoint
g.cmd(b'bc', b'T05thread:01;')
# assume that none of the first instructions is executed again
# breaking the order of the breakpoints
self.check_pc(g, steps[-1])
- logger.info('successfully reached %x' % steps[-1])
+ self.log.info('successfully reached %x' % steps[-1])
g.close()
- logger.info('exiting gdb and qemu')
+ self.log.info('exiting gdb and qemu')
vm.shutdown()
diff --git a/tests/functional/x86_64/test_acpi_bits.py
b/tests/functional/x86_64/test_acpi_bits.py
index 8e0563a97b..9a2816533d 100755
--- a/tests/functional/x86_64/test_acpi_bits.py
+++ b/tests/functional/x86_64/test_acpi_bits.py
@@ -121,10 +121,10 @@ def __init__(self, *args, **kwargs):
self._debugcon_log = 'debugcon-log.txt'
def _print_log(self, log):
- self.logger.info('\nlogs from biosbits follows:')
- self.logger.info('==========================================\n')
- self.logger.info(log)
- self.logger.info('==========================================\n')
+ self.log.info('\nlogs from biosbits follows:')
+ self.log.info('==========================================\n')
+ self.log.info(log)
+ self.log.info('==========================================\n')
def copy_bits_config(self):
""" copies the bios bits config file into bits.
@@ -138,8 +138,8 @@ def copy_bits_config(self):
self.assertTrue(os.path.exists(bits_config_file))
self.assertTrue(os.path.exists(target_config_dir))
shutil.copy2(bits_config_file, target_config_dir)
- self.logger.info('copied config file %s to %s',
- bits_config_file, target_config_dir)
+ self.log.info('copied config file %s to %s',
+ bits_config_file, target_config_dir)
def copy_test_scripts(self):
"""copies the python test scripts into bits. """
@@ -163,8 +163,8 @@ def copy_test_scripts(self):
newfilename = os.path.splitext(filename)[0] + '.py'
shutil.copy2(os.path.join(bits_test_dir, filename),
os.path.join(target_test_dir, newfilename))
- self.logger.info('copied test file %s to %s',
- filename, target_test_dir)
+ self.log.info('copied test file %s to %s',
+ filename, target_test_dir)
# now remove the pyc test file if it exists, otherwise the
# changes in the python test script won't be executed.
@@ -172,9 +172,9 @@ def copy_test_scripts(self):
if os.access(os.path.join(target_test_dir, testfile_pyc),
os.F_OK):
os.remove(os.path.join(target_test_dir, testfile_pyc))
- self.logger.info('removed compiled file %s',
- os.path.join(target_test_dir,
- testfile_pyc))
+ self.log.info('removed compiled file %s',
+ os.path.join(target_test_dir,
+ testfile_pyc))
def fix_mkrescue(self, mkrescue):
""" grub-mkrescue is a bash script with two variables, 'prefix' and
@@ -216,7 +216,7 @@ def generate_bits_iso(self):
self.fix_mkrescue(mkrescue_script)
- self.logger.info('using grub-mkrescue for generating biosbits iso ...')
+ self.log.info('using grub-mkrescue for generating biosbits iso ...')
try:
if os.getenv('V') or os.getenv('BITS_DEBUG'):
@@ -225,7 +225,7 @@ def generate_bits_iso(self):
stdout=subprocess.PIPE,
stderr=subprocess.STDOUT,
check=True)
- self.logger.info("grub-mkrescue output %s" % proc.stdout)
+ self.log.info("grub-mkrescue output %s" % proc.stdout)
else:
subprocess.check_call([mkrescue_script, '-o',
iso_file, bits_dir],
@@ -238,11 +238,10 @@ def generate_bits_iso(self):
self.assertTrue(os.access(iso_file, os.R_OK))
- self.logger.info('iso file %s successfully generated.', iso_file)
+ self.log.info('iso file %s successfully generated.', iso_file)
def setUp(self): # pylint: disable=arguments-differ
super().setUp()
- self.logger = self.log
prebuiltDir = self.scratch_file('prebuilt')
if not os.path.isdir(prebuiltDir):
@@ -333,7 +332,7 @@ def test_acpi_smbios_bits(self):
# in batch mode and then automatically initiate a vm shutdown.
self._vm.event_wait('SHUTDOWN', timeout=BITS_TIMEOUT)
self._vm.wait(timeout=None)
- self.logger.debug("Checking console output ...")
+ self.log.debug("Checking console output ...")
self.parse_log()
if __name__ == '__main__':
--
2.50.1
