From f3712a972a37591249a2dacd223192302a447a4a Mon Sep 17 00:00:00 2001 From: Christian Theune Date: Thu, 19 Dec 2024 11:30:51 +0100 Subject: [PATCH] fixes for nixos 24.11 --- setup.py | 2 +- src/fc/qemu/agent.py | 10 +++---- tests/conftest.py | 58 ++++++++++++++++--------------------- tests/hazmat/test_ceph.py | 7 +++-- tests/hazmat/test_volume.py | 4 +-- tests/test_agent.py | 4 +-- tests/test_binenv.py | 1 + tests/test_vm.py | 20 ++++++++++--- 8 files changed, 54 insertions(+), 52 deletions(-) diff --git a/setup.py b/setup.py index 12815ab..a6dd6cf 100644 --- a/setup.py +++ b/setup.py @@ -28,7 +28,7 @@ namespace_packages=["fc"], install_requires=[ "colorama", # ==0.3.3', - "abaez.consulate==1.1.0", + "consulate >= 1.1.0", "psutil", # ==5.4.2', "PyYaml>=5.3.1", "requests", # ==2.11.1', diff --git a/src/fc/qemu/agent.py b/src/fc/qemu/agent.py index d269e49..6d8f40e 100644 --- a/src/fc/qemu/agent.py +++ b/src/fc/qemu/agent.py @@ -3,11 +3,10 @@ import datetime import distutils.spawn import fcntl -import glob +import importlib.resources import json import math import os -import os.path as p import shutil import socket import subprocess @@ -21,7 +20,6 @@ import colorama import consulate import consulate.models.agent -import pkg_resources import requests import yaml @@ -272,9 +270,9 @@ class Agent(object): timeout_graceful = 10 system_config_template = Path("etc/qemu/qemu.vm.cfg.in") - builtin_config_template = Path( - pkg_resources.resource_filename(__name__, "qemu.vm.cfg.in") - ) + # XXX the importlib schema requiring a context manager + # is not helpful here. + builtin_config_template = Path(__file__).parent / "qemu.vm.cfg.in" consul_token = None consul_generation = -1 diff --git a/tests/conftest.py b/tests/conftest.py index 1e52219..3f27df7 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -5,8 +5,8 @@ import time import traceback from pathlib import Path +from subprocess import getoutput -import pkg_resources import pytest import structlog @@ -66,7 +66,8 @@ def test_logger(logger, method_name, event): result += fc.qemu.logging.prefix(event_prefix, output) # Ensure we get something to read on stdout in case we have errors. - print(result) + reltime = time.time() - util.test_log_start + print(f"{reltime:08.4f} {result}") if stack: print(stack) if exc: @@ -95,6 +96,18 @@ def test_logger(logger, method_name, event): util.log_data.extend(exc.splitlines()) raise structlog.DropEvent + def test_log_print(*args): + """A helper for tests to insert output into the stdout log. + + This adds the same timestamps as the default output for the + log and avoids this to become part of the output content that + we run assertions on. + """ + reltime = time.time() - util.test_log_start + print(f"{reltime:08.4f}", *args) + + util.test_log_print = test_log_print + structlog.configure( processors=( ([structlog.processors.format_exc_info] if log_exceptions else []) @@ -108,6 +121,7 @@ def reset_structlog(setup_structlog): from fc.qemu import util util.log_data = [] + util.test_log_start = time.time() util.test_log_options = {"show_methods": [], "show_events": []} @@ -173,37 +187,15 @@ def clean(): yield clean() - - print( - subprocess.check_output( - "free && sync && echo 3 > /proc/sys/vm/drop_caches && free", - shell=True, - ).decode("ascii") - ) - print( - subprocess.check_output( - "ceph df", - shell=True, - ).decode("ascii") - ) print( - subprocess.check_output( - "ps auxf", - shell=True, - ).decode("ascii") - ) - print( - subprocess.check_output( - "df -h", - shell=True, - ).decode("ascii") - ) - print( - subprocess.check_output( - "rbd showmapped", - shell=True, - ).decode("ascii") + getoutput("free && sync && echo 3 > /proc/sys/vm/drop_caches && free") ) + print(getoutput("ceph df")) + print(getoutput("ps auxf")) + print(getoutput("df -h")) + print(getoutput("rbd showmapped")) + print(getoutput("journalctl --since -30s")) + print(getoutput("tail -n 50 /var/log/vm/*")) @pytest.fixture(autouse=True) @@ -224,8 +216,8 @@ def vm(clean_environment, monkeypatch, tmpdir): import fc.qemu.hazmat.qemu monkeypatch.setattr(fc.qemu.hazmat.qemu.Qemu, "guestagent_timeout", 0.1) - fixtures = pkg_resources.resource_filename(__name__, "fixtures") - shutil.copy(fixtures + "/simplevm.yaml", "/etc/qemu/vm/simplevm.cfg") + simplevm_cfg = Path(__file__).parent / "fixtures" / "simplevm.yaml" + shutil.copy(simplevm_cfg, "/etc/qemu/vm/simplevm.cfg") Path("/etc/qemu/vm/.simplevm.cfg.staging").unlink(missing_ok=True) vm = Agent("simplevm") diff --git a/tests/hazmat/test_ceph.py b/tests/hazmat/test_ceph.py index fb8f1cf..981f0e7 100644 --- a/tests/hazmat/test_ceph.py +++ b/tests/hazmat/test_ceph.py @@ -54,7 +54,7 @@ def test_multiple_images_raises_error(ceph_inst): @pytest.mark.timeout(60) @pytest.mark.live() def test_rbd_pool_migration(ceph_inst, patterns) -> None: - ceph_inst.cfg["tmp_size"] = 50 * 1024 * 1024 + ceph_inst.cfg["tmp_size"] = 500 * 1024 * 1024 ceph_inst.cfg["swap_size"] = 50 * 1024 * 1024 ceph_inst.cfg["root_size"] = 50 * 1024 * 1024 rbd.RBD().create( @@ -83,6 +83,9 @@ def test_rbd_pool_migration(ceph_inst, patterns) -> None: first_start.optional( """ waiting interval=0 machine=simplevm remaining=4 subsystem=ceph volume=rbd.hdd/simplevm.tmp +sgdisk> Setting name! +sgdisk> partNum is 0 +mkfs.xfs> mkfs.xfs: small data volume, ignoring data volume stripe unit 128 and stripe width 128 """ ) first_start.in_order( @@ -138,8 +141,6 @@ def test_rbd_pool_migration(ceph_inst, patterns) -> None: sgdisk> The operation has completed successfully. sgdisk machine=simplevm returncode=0 subsystem=ceph volume=rbd.hdd/simplevm.tmp sgdisk args=-a 8192 -n 1:8192:0 -c "1:tmp" -t 1:8300 "/dev/rbd/rbd.hdd/simplevm.tmp" machine=simplevm subsystem=ceph volume=rbd.hdd/simplevm.tmp -sgdisk> Setting name! -sgdisk> partNum is 0 sgdisk> The operation has completed successfully. sgdisk machine=simplevm returncode=0 subsystem=ceph volume=rbd.hdd/simplevm.tmp partprobe args=/dev/rbd/rbd.hdd/simplevm.tmp machine=simplevm subsystem=ceph volume=rbd.hdd/simplevm.tmp diff --git a/tests/hazmat/test_volume.py b/tests/hazmat/test_volume.py index 87857e5..e19ca2c 100644 --- a/tests/hazmat/test_volume.py +++ b/tests/hazmat/test_volume.py @@ -159,7 +159,7 @@ def test_volume_mkswap(ceph_inst): @pytest.mark.timeout(60) def test_volume_tmp_mkfs(tmp_spec): - tmp_spec.desired_size = 100 * 1024 * 1024 + tmp_spec.desired_size = 400 * 1024 * 1024 tmp_spec.ensure_presence() with tmp_spec.volume.mapped(): tmp_spec.mkfs() @@ -205,7 +205,7 @@ def test_mount_should_fail_if_not_mapped(tmp_spec): @pytest.mark.timeout(60) @pytest.mark.live() def test_mount_snapshot(tmp_spec): - tmp_spec.desired_size = 100 * 1024 * 1024 + tmp_spec.desired_size = 500 * 1024 * 1024 tmp_spec.ensure_presence() volume = tmp_spec.volume with volume.mapped(): diff --git a/tests/test_agent.py b/tests/test_agent.py index d4ed2f7..efb268d 100644 --- a/tests/test_agent.py +++ b/tests/test_agent.py @@ -1,9 +1,7 @@ -import os import shutil from pathlib import Path import mock -import pkg_resources import psutil import pytest @@ -14,7 +12,7 @@ @pytest.fixture def simplevm_cfg(monkeypatch): - fixtures = Path(pkg_resources.resource_filename(__name__, "fixtures")) + fixtures = Path(__file__).parent / "fixtures" source = fixtures / "simplevm.yaml" # The Qemu prefix gets adjusted automatically in the synhetic_root # auto-use fixture that checks whether this is a live test or not. diff --git a/tests/test_binenv.py b/tests/test_binenv.py index 5222908..934eae4 100644 --- a/tests/test_binenv.py +++ b/tests/test_binenv.py @@ -38,3 +38,4 @@ def test_no_unexpected_binaries(): @pytest.mark.unit def test_ensure_critical_module_imports(): import rados # noqa + import structlog # noqa diff --git a/tests/test_vm.py b/tests/test_vm.py index 1792213..3c79ce0 100644 --- a/tests/test_vm.py +++ b/tests/test_vm.py @@ -96,8 +96,6 @@ def test_simple_vm_lifecycle_start_stop(vm, patterns): sgdisk> The operation has completed successfully. sgdisk machine=simplevm returncode=0 subsystem=ceph volume=rbd.ssd/simplevm.tmp sgdisk args=-a 8192 -n 1:8192:0 -c "1:tmp" -t 1:8300 "/dev/rbd/rbd.ssd/simplevm.tmp" machine=simplevm subsystem=ceph volume=rbd.ssd/simplevm.tmp -sgdisk> Setting name! -sgdisk> partNum is 0 sgdisk> The operation has completed successfully. sgdisk machine=simplevm returncode=0 subsystem=ceph volume=rbd.ssd/simplevm.tmp partprobe args=/dev/rbd/rbd.ssd/simplevm.tmp machine=simplevm subsystem=ceph volume=rbd.ssd/simplevm.tmp @@ -151,6 +149,8 @@ def test_simple_vm_lifecycle_start_stop(vm, patterns): sgdisk> Creating new GPT entries in memory. rbd> /dev/rbd0 waiting interval=0 machine=simplevm remaining=... subsystem=ceph volume=rbd.ssd/simplevm.tmp +sgdisk> Setting name! +sgdisk> partNum is 0 """ ) @@ -163,7 +163,7 @@ def test_simple_vm_lifecycle_start_stop(vm, patterns): fc-create-vm> $ rbd --format json --id host1 snap ls rbd.hdd/fc-21.05-dev fc-create-vm> Snapshots: fc-create-vm> snapid name size -fc-create-vm> 4 v1 104857600 +fc-create-vm> 4 v1 524288000 fc-create-vm> $ rbd --id host1 clone rbd.hdd/fc-21.05-dev@v1 rbd.ssd/simplevm.root fc-create-vm> fc-create-vm> Finished @@ -375,7 +375,10 @@ def test_vm_not_running_here(vm, capsys): ) -@pytest.mark.timeout(60) +# This test is really slow and it appears that a lot of time is due to +# locking/unlocking (or rather: breaking locks) in Ceph taking around 5 +# seconds each time ... +@pytest.mark.timeout(90) @pytest.mark.live def test_crashed_vm_clean_restart(vm): util.test_log_options["show_events"] = [ @@ -386,6 +389,7 @@ def test_crashed_vm_clean_restart(vm): "shutdown", ] + util.test_log_print("=== Running status() ===") vm.status() assert get_log() == Ellipsis( @@ -396,7 +400,9 @@ def test_crashed_vm_clean_restart(vm): rbd-status machine=simplevm presence=missing subsystem=ceph volume=rbd.ssd/simplevm.tmp""" ) + util.test_log_print("=== Running ensure() ... ===") vm.ensure() + util.test_log_print("=== Running status() ===") vm.status() assert get_log() == Ellipsis( """\ @@ -412,11 +418,13 @@ def test_crashed_vm_clean_restart(vm): rbd-status locker=('client...', 'host1') machine=simplevm subsystem=ceph volume=rbd.ssd/simplevm.tmp""" ) + util.test_log_print("=== Killing the qemu process ===") p = vm.qemu.proc() p.kill() p.wait(2) get_log() + util.test_log_print("=== Running status() ===") vm.status() assert get_log() == Ellipsis( """\ @@ -426,8 +434,10 @@ def test_crashed_vm_clean_restart(vm): rbd-status locker=('client...', 'host1') machine=simplevm subsystem=ceph volume=rbd.ssd/simplevm.tmp""" ) + util.test_log_print("=== Running ensure() ===") vm.ensure() + util.test_log_print("=== Running status() ===") vm.status() assert get_log() == Ellipsis( """\ @@ -452,7 +462,9 @@ def test_crashed_vm_clean_restart(vm): "clean", "rbd-status", ] + util.test_log_print("=== Running stop() ===") vm.stop() + util.test_log_print("=== Running status() ===") vm.status() assert get_log() == Ellipsis( """\