diff options
85 files changed, 771 insertions, 739 deletions
diff --git a/tests/__init__.py b/tests/__init__.py index d9d314bb..259992de 100644 --- a/tests/__init__.py +++ b/tests/__init__.py @@ -5,7 +5,6 @@ import atexit import imp -import logging import os # Need to do this before any tests or virtinst import @@ -15,6 +14,7 @@ os.environ.pop("_ARC_DEBUG", None) # pylint: disable=wrong-import-position from virtinst import buildconfig +from virtinst import log # This sets all the cli bits back to their defaults imp.reload(buildconfig) @@ -27,6 +27,7 @@ virtxml = None def setup_logging(): + import logging rootLogger = logging.getLogger() for handler in rootLogger.handlers: rootLogger.removeHandler(handler) diff --git a/tests/checkprops.py b/tests/checkprops.py index ec7805c6..f2a5d499 100644 --- a/tests/checkprops.py +++ b/tests/checkprops.py @@ -1,11 +1,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import traceback import unittest import virtinst +from virtinst import log _do_skip = None @@ -28,7 +28,7 @@ class CheckPropsTest(unittest.TestCase): _do_skip = bool( result.errors or result.failures or result.skipped) except Exception: - logging.debug("unittest skip hack failed", exc_info=True) + log.debug("unittest skip hack failed", exc_info=True) if _do_skip: self.skipTest("skipping as other tests failed/skipped") diff --git a/tests/clitest.py b/tests/clitest.py index 763db21a..ae33cba4 100644 --- a/tests/clitest.py +++ b/tests/clitest.py @@ -5,7 +5,6 @@ import atexit import io -import logging import os import shlex import shutil @@ -18,6 +17,7 @@ try: except ImportError: argcomplete = None +from virtinst import log from virtinst import unattended from tests import virtinstall, virtclone, virtconvert, virtxml @@ -185,7 +185,7 @@ class Command(object): def _launch_command(self, conn): - logging.debug(self.cmdstr) + log.debug(self.cmdstr) app = self.argv[0] @@ -253,7 +253,7 @@ class Command(object): code, output = self._launch_command(conn) - logging.debug("%s\n", output) + log.debug("%s\n", output) return code, output except Exception as e: return (-1, "".join(traceback.format_exc()) + str(e)) diff --git a/tests/clonetest.py b/tests/clonetest.py index 4e5a0147..ee0c72d7 100644 --- a/tests/clonetest.py +++ b/tests/clonetest.py @@ -5,11 +5,11 @@ import unittest import os -import logging from tests import utils from virtinst import Cloner +from virtinst import log ORIG_NAME = "clone-orig" CLONE_NAME = "clone-new" @@ -140,7 +140,7 @@ class TestClone(unittest.TestCase): "when it shouldn't.") except (ValueError, RuntimeError) as e: # Exception expected - logging.debug("Received expected exception: %s", str(e)) + log.debug("Received expected exception: %s", str(e)) def testCloneStorageManaged(self): disks = ["%s/new1.img" % POOL1, "%s/new2.img" % DISKPOOL] diff --git a/tests/storage.py b/tests/storage.py index 25d85fc1..245397b5 100644 --- a/tests/storage.py +++ b/tests/storage.py @@ -3,11 +3,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import unittest from virtinst import StoragePool, StorageVolume +from virtinst import log from tests import utils @@ -67,7 +67,7 @@ def createVol(conn, poolobj, volname=None, input_vol=None, clone_vol=None): # Format here depends on libvirt-1.2.0 and later if clone_vol and conn.local_libvirt_version() < 1002000: - logging.debug("skip clone compare") + log.debug("skip clone compare") return alloc = 5 * 1024 * 1024 * 1024 diff --git a/tests/test_urls.py b/tests/test_urls.py index 32ee10b9..8164acd0 100644 --- a/tests/test_urls.py +++ b/tests/test_urls.py @@ -3,7 +3,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import re import sys @@ -15,6 +14,7 @@ from tests import utils import virtinst.progress from virtinst import Installer from virtinst import Guest +from virtinst import log # These are all functional tests os.environ.pop("VIRTINST_TEST_SUITE", None) @@ -153,7 +153,7 @@ def _testGuest(testdata, guest): treemedia = installer._treemedia # pylint: disable=protected-access fetcher = treemedia._cached_fetcher # pylint: disable=protected-access def fakeAcquireFile(filename): - logging.debug("Fake acquiring %s", filename) + log.debug("Fake acquiring %s", filename) return filename fetcher.acquireFile = fakeAcquireFile diff --git a/tests/uitests/livetests.py b/tests/uitests/livetests.py index 7b836dac..861c1106 100644 --- a/tests/uitests/livetests.py +++ b/tests/uitests/livetests.py @@ -1,11 +1,12 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import libvirt +from virtinst import log + from tests.uitests import utils as uiutils @@ -231,4 +232,4 @@ class Console(uiutils.UITestCase): pool.destroy() pool.undefine() except Exception: - logging.debug("Error cleaning up pool", exc_info=True) + log.debug("Error cleaning up pool", exc_info=True) diff --git a/tests/uitests/utils.py b/tests/uitests/utils.py index 1a40adc8..9748c70f 100644 --- a/tests/uitests/utils.py +++ b/tests/uitests/utils.py @@ -1,7 +1,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import re import time @@ -15,6 +14,8 @@ from gi.repository import Gdk import pyatspi import dogtail.utils +from virtinst import log + import tests if not dogtail.utils.isA11yEnabled(): @@ -223,7 +224,7 @@ class _FuzzyPredicate(dogtail.predicate.Predicate): return return True except Exception as e: - logging.debug( + log.debug( "got predicate exception name=%s role=%s labeller=%s: %s", self._name, self._roleName, self._labeller_text, e) @@ -495,7 +496,7 @@ class VMMDogtailApp(object): try: self._proc.send_signal(signal.SIGINT) except Exception: - logging.debug("Error terminating process", exc_info=True) + log.debug("Error terminating process", exc_info=True) self._proc = None return @@ -506,7 +507,7 @@ class VMMDogtailApp(object): self._proc = None return - logging.warning("App didn't exit gracefully from SIGINT. Killing...") + log.warning("App didn't exit gracefully from SIGINT. Killing...") try: self._proc.kill() finally: @@ -5,13 +5,12 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. - import argparse -import logging import sys from virtinst import cli from virtinst import Cloner +from virtinst import log from virtinst.cli import fail, print_stdout, print_stderr @@ -20,7 +19,7 @@ def get_clone_name(new_name, auto_clone, design): if not new_name and auto_clone: # Generate a name to use new_name = design.generate_clone_name() - logging.debug("Auto-generated clone name '%s'", new_name) + log.debug("Auto-generated clone name '%s'", new_name) if not new_name: fail(_("A name is required for the new virtual machine," @@ -204,7 +203,7 @@ def main(conn=None): print_stdout("") print_stdout(_("Clone '%s' created successfully.") % design.clone_name) - logging.debug("end clone") + log.debug("end clone") return 0 if __name__ == "__main__": # pragma: no cover diff --git a/virt-install b/virt-install index 5493426d..b22304b6 100755 --- a/virt-install +++ b/virt-install @@ -7,7 +7,6 @@ import argparse import atexit -import logging import sys import time @@ -15,6 +14,7 @@ import libvirt import virtinst from virtinst import cli +from virtinst import log from virtinst.cli import fail, print_stdout, print_stderr @@ -40,7 +40,7 @@ def supports_pxe(guest): xmlobj = virtinst.Network(nic.conn, parsexml=netobj.XMLDesc(0)) return xmlobj.can_pxe() except Exception: # pragma: no cover - logging.debug("Error checking if PXE supported", exc_info=True) + log.debug("Error checking if PXE supported", exc_info=True) return True return False @@ -81,7 +81,7 @@ def convert_old_init(options): if not options.boot: options.boot = [""] options.boot[-1] += ",init=%s" % options.init - logging.debug("Converted old --init to --boot %s", options.boot[-1]) + log.debug("Converted old --init to --boot %s", options.boot[-1]) def _do_convert_old_disks(options): @@ -109,7 +109,7 @@ def _do_convert_old_disks(options): if optstr: optstr += "," optstr += "sparse=no" - logging.debug("Converted to new style: --disk %s", optstr) + log.debug("Converted to new style: --disk %s", optstr) opts.append(optstr) options.disk = opts @@ -136,7 +136,7 @@ def convert_old_disks(options): del(options.disksize) del(options.sparse) del(options.nodisks) - logging.debug("Distilled --disk options: %s", options.disk) + log.debug("Distilled --disk options: %s", options.disk) def convert_old_os_options(options): @@ -160,7 +160,7 @@ def convert_old_cpuset(options): newvcpus = options.vcpus or [] newvcpus.append(",cpuset=%s" % options.cpuset) options.vcpus = newvcpus - logging.debug("Generated compat cpuset: --vcpus %s", options.vcpus[-1]) + log.debug("Generated compat cpuset: --vcpus %s", options.vcpus[-1]) def convert_old_networks(options): @@ -204,7 +204,7 @@ def convert_old_networks(options): del(options.nonetworks) options.network = networks - logging.debug("Distilled --network options: %s", options.network) + log.debug("Distilled --network options: %s", options.network) def convert_old_graphics(options): @@ -241,7 +241,7 @@ def convert_old_graphics(options): if keymap: optstr += ",keymap=%s" % keymap - logging.debug("--graphics compat generated: %s", optstr) + log.debug("--graphics compat generated: %s", optstr) options.graphics = [optstr] @@ -321,7 +321,7 @@ def _show_nographics_warnings(options, guest, installer): return if installer.cdrom: - logging.warning(_("CDROM media does not print to the text console " + log.warning(_("CDROM media does not print to the text console " "by default, so you likely will not see text install output. " "You might want to use --location.") + " " + _cdrom_location_man_page) @@ -334,7 +334,7 @@ def _show_nographics_warnings(options, guest, installer): # they likely won't see any output. if not guest.devices.console: - logging.warning(_("No --console device added, you likely will not " + log.warning(_("No --console device added, you likely will not " "see text install output from the guest.")) return @@ -348,17 +348,17 @@ def _show_memory_warnings(guest): minram = (res.get_minimum_ram(guest.os.arch) or 0) if minram: if (minram // 1024) > guest.currentMemory: - logging.warning(_("Requested memory %s MiB is less than the " + log.warning(_("Requested memory %s MiB is less than the " "recommended %s MiB for OS %s"), rammb, minram // (1024 * 1024), guest.osinfo.name) elif rammb < 17: - logging.warning(_("Requested memory %s MiB is abnormally low. " + log.warning(_("Requested memory %s MiB is abnormally low. " "Were you trying to specify GiB?"), rammb) def show_warnings(options, guest, installer, osdata): if options.pxe and not supports_pxe(guest): - logging.warning(_("The guest's network configuration does not support " + log.warning(_("The guest's network configuration does not support " "PXE")) # Limit it to hvm x86 guests which presently our defaults @@ -367,7 +367,7 @@ def show_warnings(options, guest, installer, osdata): not osdata.is_none and not osdata.name == "generic" and guest.os.is_x86() and guest.os.is_hvm()): - logging.warning(_("No operating system detected, VM performance may " + log.warning(_("No operating system detected, VM performance may " "suffer. Specify an OS with --os-variant for optimal results.")) _show_memory_warnings(guest) @@ -630,13 +630,13 @@ def start_install(guest, installer, options): if not conscb and options.wait is None: # If there isn't any console to actually connect up, # default to --wait -1 to get similarish behavior - logging.warning(_("No console to launch for the guest, " + log.warning(_("No console to launch for the guest, " "defaulting to --wait -1")) options.wait = -1 waithandler = WaitHandler(options.wait) meter = cli.get_meter() - logging.debug("Guest.has_install_phase: %s", + log.debug("Guest.has_install_phase: %s", installer.has_install_phase()) # we've got everything -- try to start the install @@ -671,7 +671,7 @@ def start_install(guest, installer, options): options.destroy_on_exit) except KeyboardInterrupt: # pragma: no cover - logging.debug("", exc_info=True) + log.debug("", exc_info=True) print_stderr(_("Domain install interrupted.")) raise except Exception as e: @@ -694,7 +694,7 @@ def check_domain(installer, domain, conscb, transient, waithandler): try: dominfo = domain.info() state = dominfo[0] - logging.debug("Domain state after install: %s", state) + log.debug("Domain state after install: %s", state) if state == libvirt.VIR_DOMAIN_CRASHED: fail(_("Domain has crashed.")) # pragma: no cover @@ -702,7 +702,7 @@ def check_domain(installer, domain, conscb, transient, waithandler): return not domain.isActive() except libvirt.libvirtError as e: if transient and e.get_error_code() == libvirt.VIR_ERR_NO_DOMAIN: - logging.debug("transient VM shutdown and disappeared.") + log.debug("transient VM shutdown and disappeared.") return True raise # pragma: no cover @@ -923,7 +923,7 @@ def _destroy_on_exit(domain): domain.destroy() # pragma: no cover except libvirt.libvirtError as e: # pragma: no cover if e.get_error_code() != libvirt.VIR_ERR_NO_DOMAIN: - logging.debug("Error invoking atexit destroy_on_exit", + log.debug("Error invoking atexit destroy_on_exit", exc_info=True) @@ -998,7 +998,7 @@ if __name__ == "__main__": # pragma: no cover except SystemExit as sys_e: sys.exit(sys_e.code) except KeyboardInterrupt: - logging.debug("", exc_info=True) + log.debug("", exc_info=True) print_stderr(_("Installation aborted at user request")) except Exception as main_e: fail(main_e) diff --git a/virt-manager b/virt-manager index 5d99c7da..5da572f3 100755 --- a/virt-manager +++ b/virt-manager @@ -7,7 +7,6 @@ # See the COPYING file in the top-level directory. import argparse -import logging import os import signal import sys @@ -20,6 +19,7 @@ from gi.repository import LibvirtGLib from virtinst import BuildConfig from virtinst import VirtinstConnection from virtinst import cli +from virtinst import log # This is massively heavy handed, but I can't figure out any way to shut # up the slew of gtk deprecation warnings that clog up our very useful @@ -36,7 +36,7 @@ except (ValueError, AttributeError): def _show_startup_error(msg, details): - logging.debug("Error starting virt-manager: %s\n%s", msg, details, + log.debug("Error starting virt-manager: %s\n%s", msg, details, exc_info=True) from virtManager.error import vmmErrorDialog err = vmmErrorDialog.get_instance() @@ -81,7 +81,7 @@ def _import_gtk(leftovers): msg = str(e) if display: msg += ": Could not open display: %s" % display - logging.debug("".join(traceback.format_exc())) + log.debug("".join(traceback.format_exc())) print(msg) sys.exit(1) finally: @@ -220,14 +220,14 @@ def main(): cli.setupLogging("virt-manager", options.debug, False, False) import virtManager - logging.debug("virt-manager version: %s", BuildConfig.version) - logging.debug("virtManager import: %s", str(virtManager)) + log.debug("virt-manager version: %s", BuildConfig.version) + log.debug("virtManager import: %s", str(virtManager)) if BuildConfig.running_from_srcdir: _setup_gsettings_path(BuildConfig.gsettings_dir) if options.trace_libvirt: - logging.debug("Libvirt tracing requested") + log.debug("Libvirt tracing requested") import virtManager.module_trace import libvirt virtManager.module_trace.wrap_module(libvirt, @@ -268,11 +268,11 @@ def main(): if leftovers: raise RuntimeError("Unhandled command line options '%s'" % leftovers) - logging.debug("PyGObject version: %d.%d.%d", + log.debug("PyGObject version: %d.%d.%d", gi.version_info[0], gi.version_info[1], gi.version_info[2]) - logging.debug("GTK version: %d.%d.%d", + log.debug("GTK version: %d.%d.%d", Gtk.get_major_version(), Gtk.get_minor_version(), Gtk.get_micro_version()) @@ -333,7 +333,7 @@ def main(): from gi.repository import GLib def _sigint_handler(user_data): ignore = user_data - logging.debug("Received KeyboardInterrupt. Exiting application.") + log.debug("Received KeyboardInterrupt. Exiting application.") engine.exit_app() GLib.unix_signal_add(GLib.PRIORITY_DEFAULT, signal.SIGINT, _sigint_handler, None) @@ -345,7 +345,7 @@ if __name__ == "__main__": try: main() except KeyboardInterrupt: - logging.debug("Received KeyboardInterrupt. Exiting application.") + log.debug("Received KeyboardInterrupt. Exiting application.") except Exception as run_e: if "Gtk" not in globals(): raise @@ -6,7 +6,6 @@ # See the COPYING file in the top-level directory. import difflib -import logging import re import sys @@ -14,6 +13,7 @@ import libvirt import virtinst from virtinst import cli +from virtinst import log from virtinst import xmlutil from virtinst.cli import fail, print_stdout, print_stderr @@ -44,9 +44,9 @@ def get_diff(origxml, newxml): tofile="Altered XML")) if ret: - logging.debug("XML diff:\n%s", ret) + log.debug("XML diff:\n%s", ret) else: - logging.debug("No XML diff, didn't generate any change.") + log.debug("No XML diff, didn't generate any change.") return ret @@ -82,7 +82,7 @@ def get_domain_and_guest(conn, domstr): domain = conn.lookupByName(domstr) except Exception: # In case the VM has a UUID or ID for a name - logging.debug("Error looking up domain by name", exc_info=True) + log.debug("Error looking up domain by name", exc_info=True) if isint: domain = conn.lookupByID(int(domstr)) elif isuuid: @@ -254,7 +254,7 @@ def setup_device(dev): if getattr(dev, "DEVICE_TYPE", None) != "disk": return - logging.debug("Doing setup for disk=%s", dev) + log.debug("Doing setup for disk=%s", dev) dev.build_storage(cli.get_meter()) @@ -347,7 +347,7 @@ def prepare_changes(xmlobj, options, parserclass): diff = get_diff(origxml, newxml) if not diff: - logging.warning(_("No XML diff was generated. The requested " + log.warning(_("No XML diff was generated. The requested " "changes will have no effect.")) if options.print_diff: @@ -521,7 +521,7 @@ def main(conn=None): update_changes(domain, devs, action, options.confirm) performed_update = True else: - logging.warning( + log.warning( _("The VM is not running, --update is inapplicable.")) if not options.define: # --update and --no-define passed, so we are done @@ -555,7 +555,7 @@ def main(conn=None): print_stdout( _("Changes will take effect after the domain is fully powered off.")) elif defined_xml_is_unchanged(conn, domain, original_xml): - logging.warning(_("XML did not change after domain define. You may " + log.warning(_("XML did not change after domain define. You may " "have changed a value that libvirt is setting by default.")) return 0 @@ -567,7 +567,7 @@ if __name__ == "__main__": # pragma: no cover except SystemExit as sys_e: sys.exit(sys_e.code) except KeyboardInterrupt: - logging.debug("", exc_info=True) + log.debug("", exc_info=True) print_stderr(_("Aborted at user request")) except Exception as main_e: fail(main_e) diff --git a/virtManager/about.py b/virtManager/about.py index e8b50c41..d36add34 100644 --- a/virtManager/about.py +++ b/virtManager/about.py @@ -4,7 +4,7 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging +from virtinst import log from .baseclass import vmmGObjectUI @@ -30,13 +30,13 @@ class vmmAbout(vmmGObjectUI): }) def show(self, parent): - logging.debug("Showing about") + log.debug("Showing about") self.topwin.set_version(self.config.get_appversion()) self.topwin.set_transient_for(parent) self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing about") + log.debug("Closing about") self.topwin.hide() return 1 diff --git a/virtManager/addhardware.py b/virtManager/addhardware.py index 8cd7f751..c4f26e60 100644 --- a/virtManager/addhardware.py +++ b/virtManager/addhardware.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import traceback from gi.repository import Gtk @@ -15,6 +14,7 @@ from virtinst import (DeviceChannel, DeviceConsole, DeviceInput, DeviceInterface, DevicePanic, DeviceParallel, DeviceRedirdev, DeviceRng, DeviceSerial, DeviceSmartcard, DeviceSound, DeviceTpm, DeviceVideo, DeviceVsock, DeviceWatchdog) +from virtinst import log from . import uiutil from .fsdetails import vmmFSDetails @@ -127,7 +127,7 @@ class vmmAddHardware(vmmGObjectUI): self._set_initial_state() def show(self, parent): - logging.debug("Showing addhw") + log.debug("Showing addhw") self._reset_state() self.topwin.set_transient_for(parent) self.topwin.present() @@ -137,7 +137,7 @@ class vmmAddHardware(vmmGObjectUI): def close(self, ignore1=None, ignore2=None): if self.is_visible(): - logging.debug("Closing addhw") + log.debug("Closing addhw") self.topwin.hide() if self._storagebrowser: self._storagebrowser.close() @@ -385,7 +385,7 @@ class vmmAddHardware(vmmGObjectUI): vm.hotplug(**hotplug_args) except Exception as e: did_hotplug = True - logging.debug("Hotplug failed: %s", str(e)) + log.debug("Hotplug failed: %s", str(e)) hotplug_err = ((str(e), "".join(traceback.format_exc()))) if did_hotplug and not hotplug_err: @@ -1285,22 +1285,22 @@ class vmmAddHardware(vmmGObjectUI): dev.get_parent_pool()): poolname = dev.get_parent_pool().name() - logging.debug("Running build_storage() for device=%s", dev) + log.debug("Running build_storage() for device=%s", dev) dev.build_storage(meter=asyncjob.get_meter()) - logging.debug("build_storage() complete") + log.debug("build_storage() complete") if poolname: try: pool = self.conn.get_pool(poolname) self.idle_add(pool.refresh) except Exception: - logging.debug("Error looking up pool=%s for refresh after " + log.debug("Error looking up pool=%s for refresh after " "storage creation.", poolname, exc_info=True) def _add_device(self, dev): xml = dev.get_xml() - logging.debug("Adding device:\n%s", xml) + log.debug("Adding device:\n%s", xml) if self._remove_usb_controller: kwargs = {} @@ -1317,7 +1317,7 @@ class vmmAddHardware(vmmGObjectUI): controller = getattr(dev, "vmm_controller", None) if controller is not None: - logging.debug("Adding controller:\n%s", + log.debug("Adding controller:\n%s", controller.get_xml()) # Hotplug device attach_err = False @@ -1326,7 +1326,7 @@ class vmmAddHardware(vmmGObjectUI): self.vm.attach_device(controller) self.vm.attach_device(dev) except Exception as e: - logging.debug("Device could not be hotplugged: %s", str(e)) + log.debug("Device could not be hotplugged: %s", str(e)) attach_err = (str(e), "".join(traceback.format_exc())) if attach_err: @@ -1433,7 +1433,7 @@ class vmmAddHardware(vmmGObjectUI): def _build_xmleditor_device(self, srcdev): xml = self._xmleditor.get_xml() - logging.debug("Using XML from xmleditor:\n%s", xml) + log.debug("Using XML from xmleditor:\n%s", xml) devclass = srcdev.__class__ dev = devclass(srcdev.conn, parsexml=xml) diff --git a/virtManager/addstorage.py b/virtManager/addstorage.py index d6604606..6eea08b2 100644 --- a/virtManager/addstorage.py +++ b/virtManager/addstorage.py @@ -3,12 +3,13 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os from gi.repository import Gtk import virtinst +from virtinst import log + from . import uiutil from .baseclass import vmmGObjectUI @@ -49,7 +50,7 @@ class vmmAddStorage(vmmGObjectUI): avail = int(pool.get_available()) return float(avail / 1024.0 / 1024.0 / 1024.0) except Exception: - logging.exception("Error determining host disk space") + log.exception("Error determining host disk space") return -1 def _update_host_space(self): @@ -85,7 +86,7 @@ class vmmAddStorage(vmmGObjectUI): if not broken_paths: return - logging.debug("No search access for dirs: %s", broken_paths) + log.debug("No search access for dirs: %s", broken_paths) resp, chkres = src.err.warn_chkbox( _("The emulator may not have search permissions " "for the path '%s'.") % path, @@ -98,7 +99,7 @@ class vmmAddStorage(vmmGObjectUI): if not resp: return - logging.debug("Attempting to correct permission issues.") + log.debug("Attempting to correct permission issues.") errors = virtinst.DeviceDisk.fix_path_search( conn.get_backend(), searchdata) if not errors: @@ -113,7 +114,7 @@ class vmmAddStorage(vmmGObjectUI): details += "%s : %s\n" % (p, error) details += "\nIt is very likely the VM will fail to start up." - logging.debug("Permission errors:\n%s", details) + log.debug("Permission errors:\n%s", details) ignore, chkres = src.err.err_chkbox(errmsg, details, _("Don't ask about these directories again.")) @@ -184,11 +185,11 @@ class vmmAddStorage(vmmGObjectUI): fmt = self.conn.get_default_storage_format() if disk.get_vol_install().supports_property("format"): - logging.debug("Using default prefs format=%s for path=%s", + log.debug("Using default prefs format=%s for path=%s", fmt, disk.path) disk.get_vol_install().format = fmt else: - logging.debug("path=%s can not use default prefs format=%s, " + log.debug("path=%s can not use default prefs format=%s, " "not setting it", disk.path, fmt) return disk diff --git a/virtManager/baseclass.py b/virtManager/baseclass.py index 78902e83..b2c90263 100644 --- a/virtManager/baseclass.py +++ b/virtManager/baseclass.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import sys import threading @@ -16,6 +15,8 @@ from gi.repository import GLib from gi.repository import GObject from gi.repository import Gtk +from virtinst import log + from . import config @@ -93,7 +94,7 @@ class vmmGObject(GObject.GObject): for h in self._gobject_timeouts[:]: self.remove_gobject_timeout(h) except Exception: - logging.exception("Error cleaning up %s", self) + log.exception("Error cleaning up %s", self) self.__cleaned_up = True @@ -110,7 +111,7 @@ class vmmGObject(GObject.GObject): if config.vmmConfig.is_initialized() and self._leak_check: self.config.remove_object(self.object_key) except Exception: - logging.exception("Error removing %s", self.object_key) + log.exception("Error removing %s", self.object_key) @property def config(self): @@ -190,7 +191,7 @@ class vmmGObject(GObject.GObject): def _logtrace(self, msg=""): if msg: msg += " " - logging.debug("%s(%s %s)\n:%s", + log.debug("%s(%s %s)\n:%s", msg, self.object_key, self._refcount(), "".join(traceback.format_stack())) @@ -304,7 +305,7 @@ class vmmGObjectUI(vmmGObject): self.topwin = None self._err = None except Exception: - logging.exception("Error cleaning up %s", self) + log.exception("Error cleaning up %s", self) self.__cleaned_up = True @@ -335,7 +336,7 @@ class vmmGObjectUI(vmmGObject): except Exception: # If a cursor icon theme isn't installed this can cause errors # https://bugzilla.redhat.com/show_bug.cgi?id=1516588 - logging.debug("Error setting cursor_type=%s", + log.debug("Error setting cursor_type=%s", cursor_type, exc_info=True) def set_finish_cursor(self): diff --git a/virtManager/clone.py b/virtManager/clone.py index d9ed27c3..507727a2 100644 --- a/virtManager/clone.py +++ b/virtManager/clone.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os from gi.repository import Gtk @@ -13,6 +12,7 @@ from gi.repository import Gdk import virtinst from virtinst import Cloner from virtinst import DeviceInterface +from virtinst import log from . import uiutil from .baseclass import vmmGObjectUI @@ -174,7 +174,7 @@ class vmmCloneVM(vmmGObjectUI): return None def show(self, parent, vm): - logging.debug("Showing clone wizard") + log.debug("Showing clone wizard") self._set_vm(vm) self.reset_state() self.topwin.set_transient_for(parent) @@ -182,7 +182,7 @@ class vmmCloneVM(vmmGObjectUI): self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing clone wizard") + log.debug("Closing clone wizard") self.change_mac_close() self.change_storage_close() self.topwin.hide() @@ -415,7 +415,7 @@ class vmmCloneVM(vmmGObjectUI): cd.skip_target = skip_targets cd.setup_original() except Exception as e: - logging.exception("Disk target '%s' caused clone error", + log.exception("Disk target '%s' caused clone error", force_target) storage_add(str(e)) continue @@ -436,13 +436,13 @@ class vmmCloneVM(vmmGObjectUI): # Generate disk path, make sure that works clone_path = self.generate_clone_path_name(path) - logging.debug("Original path: %s\nGenerated clone path: %s", + log.debug("Original path: %s\nGenerated clone path: %s", path, clone_path) cd.clone_paths = clone_path size = cd.original_disks[0].get_size() except Exception as e: - logging.exception("Error setting generated path '%s'", + log.exception("Error setting generated path '%s'", clone_path) storage_add(str(e)) @@ -479,7 +479,7 @@ class vmmCloneVM(vmmGObjectUI): newpath = self.generate_clone_path_name(origpath, newname) row[STORAGE_INFO_NEW_PATH] = newpath except Exception as e: - logging.debug("Generating new path from clone name failed: %s", + log.debug("Generating new path from clone name failed: %s", str(e)) def build_storage_entry(self, disk, storage_box): @@ -603,7 +603,7 @@ class vmmCloneVM(vmmGObjectUI): self.clone_design.clone_paths = new_disks except Exception as e: # Just log the error and go on. The UI will fail later if needed - logging.debug("Error setting clone_paths: %s", str(e)) + log.debug("Error setting clone_paths: %s", str(e)) # If any storage cannot be cloned or shared, don't allow cloning clone = True @@ -860,7 +860,7 @@ class vmmCloneVM(vmmGObjectUI): pool = self.conn.get_pool(poolname) self.idle_add(pool.refresh) except Exception: - logging.debug("Error looking up pool=%s for refresh after " + log.debug("Error looking up pool=%s for refresh after " "VM clone.", poolname, exc_info=True) def change_storage_browse(self, ignore): diff --git a/virtManager/config.py b/virtManager/config.py index e8d086b6..ded3b2e4 100644 --- a/virtManager/config.py +++ b/virtManager/config.py @@ -5,13 +5,13 @@ # See the COPYING file in the top-level directory. import os -import logging from gi.repository import Gio from gi.repository import GLib from gi.repository import Gtk from virtinst import DomainCpu +from virtinst import log from .inspection import vmmInspection from .keyring import vmmKeyring, vmmSecret @@ -642,7 +642,7 @@ class vmmConfig(object): _type == self.CONFIG_DIR_FLOPPY_MEDIA): path = os.getcwd() - logging.debug("directory for type=%s returning=%s", _type, path) + log.debug("directory for type=%s returning=%s", _type, path) return path def set_default_directory(self, folder, _type): @@ -650,7 +650,7 @@ class vmmConfig(object): if not key: return - logging.debug("saving directory for type=%s to %s", key, folder) + log.debug("saving directory for type=%s to %s", key, folder) self.conf.set("/paths/%s-default" % key, folder) # Keyring / VNC password dealings diff --git a/virtManager/connect.py b/virtManager/connect.py index a46a05e7..8c881dd5 100644 --- a/virtManager/connect.py +++ b/virtManager/connect.py @@ -6,11 +6,12 @@ import glob import os -import logging import urllib.parse from gi.repository import Gtk +from virtinst import log + from . import uiutil from .baseclass import vmmGObjectUI from .connmanager import vmmConnectionManager @@ -77,17 +78,17 @@ class vmmConnect(vmmGObjectUI): return None def cancel(self, ignore1=None, ignore2=None): - logging.debug("Cancelling open connection") + log.debug("Cancelling open connection") self.close() return 1 def close(self, ignore1=None, ignore2=None): - logging.debug("Closing open connection") + log.debug("Closing open connection") self.topwin.hide() def show(self, parent): - logging.debug("Showing open connection") + log.debug("Showing open connection") if self.is_visible(): self.topwin.present() return @@ -273,7 +274,7 @@ class vmmConnect(vmmGObjectUI): else: uri = self.widget("uri-entry").get_text() - logging.debug("Generate URI=%s, auto=%s", uri, auto) + log.debug("Generate URI=%s, auto=%s", uri, auto) conn = vmmConnectionManager.get_instance().add_conn(uri) conn.set_autoconnect(auto) diff --git a/virtManager/connectauth.py b/virtManager/connectauth.py index c6858200..31acd6a3 100644 --- a/virtManager/connectauth.py +++ b/virtManager/connectauth.py @@ -5,7 +5,6 @@ # See the COPYING file in the top-level directory. import collections -import logging import os import re import time @@ -16,6 +15,8 @@ from gi.repository import Gtk import libvirt +from virtinst import log + from .baseclass import vmmGObjectUI from . import uiutil @@ -25,7 +26,7 @@ def do_we_have_session(): try: bus = Gio.bus_get_sync(Gio.BusType.SYSTEM, None) except Exception: - logging.exception("Error getting system bus handle") + log.exception("Error getting system bus handle") return # Check systemd @@ -36,10 +37,10 @@ def do_we_have_session(): "org.freedesktop.login1.Manager", None) ret = manager.GetSessionByPID("(u)", pid) - logging.debug("Found login1 session=%s", ret) + log.debug("Found login1 session=%s", ret) return True except Exception: - logging.exception("Couldn't connect to logind") + log.exception("Couldn't connect to logind") return False @@ -126,7 +127,7 @@ def creds_dialog(creds, cbdata): dialogobj = _vmmConnectAuth(creds) ret = dialogobj.run() except Exception: - logging.exception("Error from creds dialog") + log.exception("Error from creds dialog") ret = -1 retipc.append(ret) @@ -148,7 +149,7 @@ def connect_error(conn, errmsg, tb, warnconsole): show_errmsg = True if conn.is_remote(): - logging.debug("connect_error: conn transport=%s", + log.debug("connect_error: conn transport=%s", conn.get_uri_transport()) if re.search(r"nc: .* -- 'U'", tb): hint += _("The remote host requires a version of netcat/nc " diff --git a/virtManager/connection.py b/virtManager/connection.py index ec6dd2e4..719fc1ba 100644 --- a/virtManager/connection.py +++ b/virtManager/connection.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import threading import time @@ -13,6 +12,7 @@ import traceback import libvirt import virtinst +from virtinst import log from virtinst import pollhelpers from . import connectauth @@ -285,7 +285,7 @@ class vmmConnection(vmmGObject): try: ret.append(vol.get_xmlobj(refresh_if_nec=False)) except Exception as e: - logging.debug("Fetching volume XML failed: %s", e) + log.debug("Fetching volume XML failed: %s", e) return ret self._backend.cb_fetch_all_vols = fetch_all_vols @@ -433,7 +433,7 @@ class vmmConnection(vmmGObject): if self._storage_capable is None: self._storage_capable = self.support.conn_storage() if self._storage_capable is False: - logging.debug("Connection doesn't seem to support storage " + log.debug("Connection doesn't seem to support storage " "APIs. Skipping all storage polling.") return self._storage_capable @@ -442,7 +442,7 @@ class vmmConnection(vmmGObject): if self._network_capable is None: self._network_capable = self.support.conn_network() if self._network_capable is False: - logging.debug("Connection doesn't seem to support network " + log.debug("Connection doesn't seem to support network " "APIs. Skipping all network polling.") return self._network_capable @@ -451,7 +451,7 @@ class vmmConnection(vmmGObject): if self._interface_capable is None: self._interface_capable = self.support.conn_interface() if self._interface_capable is False: - logging.debug("Connection doesn't seem to support interface " + log.debug("Connection doesn't seem to support interface " "APIs. Skipping all interface polling.") return self._interface_capable @@ -489,13 +489,13 @@ class vmmConnection(vmmGObject): if self.support.domain_xml_inactive(vm): inact = libvirt.VIR_DOMAIN_XML_INACTIVE else: - logging.debug("Domain XML inactive flag not supported.") + log.debug("Domain XML inactive flag not supported.") if self.support.domain_xml_secure(vm): inact |= libvirt.VIR_DOMAIN_XML_SECURE act = libvirt.VIR_DOMAIN_XML_SECURE else: - logging.debug("Domain XML secure flag not supported.") + log.debug("Domain XML secure flag not supported.") return inact, act @@ -518,7 +518,7 @@ class vmmConnection(vmmGObject): return vol except Exception as e: # Errors can happen if the volume disappeared, bug 1092739 - logging.debug("Error looking up volume from path=%s: %s", + log.debug("Error looking up volume from path=%s: %s", path, e) return None @@ -530,7 +530,7 @@ class vmmConnection(vmmGObject): def _change_state(self, newstate): if self._state != newstate: self._state = newstate - logging.debug("conn=%s changed to state=%s", + log.debug("conn=%s changed to state=%s", self.get_uri(), self.get_state_text()) self.emit("state-changed") @@ -595,7 +595,7 @@ class vmmConnection(vmmGObject): # Libvirt nodedev XML fetching can be busted # https://bugzilla.redhat.com/show_bug.cgi?id=1225771 if e.get_error_code() != libvirt.VIR_ERR_NO_NODE_DEVICE: - logging.debug("Error fetching nodedev XML", exc_info=True) + log.debug("Error fetching nodedev XML", exc_info=True) continue if devtype and xmlobj.device_type != devtype: @@ -636,11 +636,11 @@ class vmmConnection(vmmGObject): newobj = define_cb(newxml) except Exception as renameerr: try: - logging.debug("Error defining new name %s XML", + log.debug("Error defining new name %s XML", obj.class_name(), exc_info=True) newobj = define_cb(origxml) except Exception as fixerr: - logging.debug("Failed to redefine original %s!", + log.debug("Failed to redefine original %s!", obj.class_name(), exc_info=True) raise RuntimeError( _("%s rename failed. Attempting to recover also " @@ -674,7 +674,7 @@ class vmmConnection(vmmGObject): eventstr = args.pop(-1) name = domain.name() - logging.debug("domain xmlmisc event: domain=%s event=%s args=%s", + log.debug("domain xmlmisc event: domain=%s event=%s args=%s", name, eventstr, args) obj = self.get_vm(name) if not obj: @@ -687,7 +687,7 @@ class vmmConnection(vmmGObject): ignore = userdata name = domain.name() - logging.debug("domain lifecycle event: domain=%s %s", name, + log.debug("domain lifecycle event: domain=%s %s", name, LibvirtEnumMap.domain_lifecycle_str(state, reason)) obj = self.get_vm(name) @@ -702,7 +702,7 @@ class vmmConnection(vmmGObject): ignore = userdata name = domain.name() - logging.debug("domain agent lifecycle event: domain=%s %s", name, + log.debug("domain agent lifecycle event: domain=%s %s", name, LibvirtEnumMap.domain_agent_lifecycle_str(state, reason)) obj = self.get_vm(name) @@ -717,7 +717,7 @@ class vmmConnection(vmmGObject): ignore = userdata name = network.name() - logging.debug("network lifecycle event: network=%s %s", + log.debug("network lifecycle event: network=%s %s", name, LibvirtEnumMap.network_lifecycle_str(state, reason)) obj = self.get_net(name) @@ -732,7 +732,7 @@ class vmmConnection(vmmGObject): ignore = userdata name = pool.name() - logging.debug("storage pool lifecycle event: pool=%s %s", + log.debug("storage pool lifecycle event: pool=%s %s", name, LibvirtEnumMap.storage_lifecycle_str(state, reason)) obj = self.get_pool(name) @@ -747,7 +747,7 @@ class vmmConnection(vmmGObject): ignore = userdata name = pool.name() - logging.debug("storage pool refresh event: pool=%s", name) + log.debug("storage pool refresh event: pool=%s", name) obj = self.get_pool(name) @@ -762,7 +762,7 @@ class vmmConnection(vmmGObject): ignore = userdata name = dev.name() - logging.debug("node device lifecycle event: nodedev=%s %s", + log.debug("node device lifecycle event: nodedev=%s %s", name, LibvirtEnumMap.nodedev_lifecycle_str(state, reason)) self.schedule_priority_tick(pollnodedev=True, force=True) @@ -772,7 +772,7 @@ class vmmConnection(vmmGObject): ignore = userdata name = dev.name() - logging.debug("node device update event: nodedev=%s", name) + log.debug("node device update event: nodedev=%s", name) obj = self.get_nodedev(name) @@ -795,10 +795,10 @@ class vmmConnection(vmmGObject): None, libvirt.VIR_DOMAIN_EVENT_ID_LIFECYCLE, self._domain_lifecycle_event, None)) self.using_domain_events = True - logging.debug("Using domain events") + log.debug("Using domain events") except Exception as e: self.using_domain_events = False - logging.debug("Error registering domain events: %s", e) + log.debug("Error registering domain events: %s", e) def _add_domain_xml_event(eventname, eventval, cb=None): if not self.using_domain_events: @@ -811,7 +811,7 @@ class vmmConnection(vmmGObject): self.get_backend().domainEventRegisterAny( None, eventid, cb, eventname)) except Exception as e: - logging.debug("Error registering %s event: %s", + log.debug("Error registering %s event: %s", eventname, e) _add_domain_xml_event("VIR_DOMAIN_EVENT_ID_BALLOON_CHANGE", 13) @@ -829,10 +829,10 @@ class vmmConnection(vmmGObject): self.get_backend().networkEventRegisterAny( None, eventid, self._network_lifecycle_event, None)) self.using_network_events = True - logging.debug("Using network events") + log.debug("Using network events") except Exception as e: self.using_network_events = False - logging.debug("Error registering network events: %s", e) + log.debug("Error registering network events: %s", e) try: _check_events_disabled() @@ -848,10 +848,10 @@ class vmmConnection(vmmGObject): self.get_backend().storagePoolEventRegisterAny( None, refreshid, self._storage_pool_refresh_event, None)) self.using_storage_pool_events = True - logging.debug("Using storage pool events") + log.debug("Using storage pool events") except Exception as e: self.using_storage_pool_events = False - logging.debug("Error registering storage pool events: %s", e) + log.debug("Error registering storage pool events: %s", e) try: _check_events_disabled() @@ -866,10 +866,10 @@ class vmmConnection(vmmGObject): None, updateid, self._node_device_update_event, None)) self.using_node_device_events = True - logging.debug("Using node device events") + log.debug("Using node device events") except Exception as e: self.using_network_events = False - logging.debug("Error registering node device events: %s", e) + log.debug("Error registering node device events: %s", e) ###################################### @@ -882,7 +882,7 @@ class vmmConnection(vmmGObject): def close(self): if not self.is_disconnected(): - logging.debug("conn.close() uri=%s", self.get_uri()) + log.debug("conn.close() uri=%s", self.get_uri()) self._closing = True try: @@ -896,7 +896,7 @@ class vmmConnection(vmmGObject): for eid in self._node_device_cb_ids: self._backend.nodeDeviceEventDeregisterAny(eid) except Exception: - logging.debug("Failed to deregister events in conn cleanup", + log.debug("Failed to deregister events in conn cleanup", exc_info=True) finally: self._domain_cb_ids = [] @@ -915,13 +915,13 @@ class vmmConnection(vmmGObject): self._remove_object_signal(obj) obj.cleanup() except Exception as e: - logging.debug("Failed to cleanup %s: %s", obj, e) + log.debug("Failed to cleanup %s: %s", obj, e) self._objects.cleanup() self._objects = _ObjectList() closeret = self._backend.close() if closeret == 1 and self.config.CLITestOptions.leak_debug: - logging.debug("LEAK: conn close() returned 1, " + log.debug("LEAK: conn close() returned 1, " "meaning refs may have leaked.") self._change_state(self._STATE_DISCONNECTED) @@ -943,7 +943,7 @@ class vmmConnection(vmmGObject): self._change_state(self._STATE_CONNECTING) - logging.debug("Scheduling background open thread for %s", + log.debug("Scheduling background open thread for %s", self.get_uri()) self._start_thread(self._open_thread, "Connect %s" % self.get_uri()) @@ -966,12 +966,12 @@ class vmmConnection(vmmGObject): if (libvirt_error_code == getattr(libvirt, "VIR_ERR_AUTH_CANCELLED", None)): - logging.debug("User cancelled auth, not raising any error.") + log.debug("User cancelled auth, not raising any error.") return False, None if (libvirt_error_code == libvirt.VIR_ERR_AUTH_FAILED and "not authorized" in libvirt_error_message.lower()): - logging.debug("Looks like we might have failed policykit " + log.debug("Looks like we might have failed policykit " "auth. Checking to see if we have a valid " "console session") if (not self.is_remote() and @@ -983,12 +983,12 @@ class vmmConnection(vmmGObject): return False, ConnectError def _populate_initial_state(self): - logging.debug("libvirt version=%s", + log.debug("libvirt version=%s", self._backend.local_libvirt_version()) - logging.debug("daemon version=%s", + log.debug("daemon version=%s", self._backend.daemon_version()) - logging.debug("conn version=%s", self._backend.conn_version()) - logging.debug("%s capabilities:\n%s", + log.debug("conn version=%s", self._backend.conn_version()) + log.debug("%s capabilities:\n%s", self.get_uri(), self.caps.get_xml()) # Try to create the default storage pool @@ -996,7 +996,7 @@ class vmmConnection(vmmGObject): try: virtinst.StoragePool.build_default_pool(self.get_backend()) except Exception as e: - logging.debug("Building default pool failed: %s", str(e)) + log.debug("Building default pool failed: %s", str(e)) self._add_conn_events() @@ -1006,7 +1006,7 @@ class vmmConnection(vmmGObject): if (not isinstance(e, AttributeError) and not self.support.is_error_nosupport(e)): raise - logging.debug("Connection doesn't support KeepAlive, " + log.debug("Connection doesn't support KeepAlive, " "skipping") # The initial tick will set up a threading event that will only @@ -1077,11 +1077,11 @@ class vmmConnection(vmmGObject): name = str(obj) if not self._objects.remove(obj): - logging.debug("Requested removal of %s=%s, but it's " + log.debug("Requested removal of %s=%s, but it's " "not in our object list.", class_name, name) continue - logging.debug("%s=%s removed", class_name, name) + log.debug("%s=%s removed", class_name, name) self._remove_object_signal(obj) obj.cleanup() @@ -1093,24 +1093,24 @@ class vmmConnection(vmmGObject): class_name = obj.class_name() if initialize_failed: - logging.debug("Blacklisting %s=%s", class_name, obj.get_name()) + log.debug("Blacklisting %s=%s", class_name, obj.get_name()) count = self._objects.add_blacklist(obj) if count <= _ObjectList.BLACKLIST_COUNT: - logging.debug("Object added in blacklist, count=%d", count) + log.debug("Object added in blacklist, count=%d", count) else: - logging.debug("Object already blacklisted?") + log.debug("Object already blacklisted?") return else: self._objects.remove_blacklist(obj) if not self._objects.add(obj): - logging.debug("New %s=%s requested, but it's already tracked.", + log.debug("New %s=%s requested, but it's already tracked.", class_name, obj.get_name()) return if not obj.is_nodedev(): # Skip nodedev logging since it's noisy and not interesting - logging.debug("%s=%s status=%s added", class_name, + log.debug("%s=%s status=%s added", class_name, obj.get_name(), obj.run_status()) if obj.is_domain(): self.emit("vm-added", obj.get_connkey()) @@ -1277,13 +1277,13 @@ class vmmConnection(vmmGObject): obj.tick(stats_update=stats_update) except Exception as e: - logging.exception("Tick for %s failed", obj) + log.exception("Tick for %s failed", obj) if (isinstance(e, libvirt.libvirtError) and (getattr(e, "get_error_code")() == libvirt.VIR_ERR_SYSTEM_ERROR)): # Try a simple getInfo call to see if conn was dropped self._backend.getInfo() - logging.debug("vm tick raised system error but " + log.debug("vm tick raised system error but " "connection doesn't seem to have dropped. " "Ignoring.") @@ -1382,13 +1382,13 @@ class vmmConnection(vmmGObject): dom = e.get_error_domain() code = e.get_error_code() - logging.debug("Error polling connection %s", + log.debug("Error polling connection %s", self.get_uri(), exc_info=True) if (dom in [from_remote, from_rpc] and code in [sys_error, internal_error]): e = None - logging.debug("Not showing user error since libvirtd " + log.debug("Not showing user error since libvirtd " "appears to have stopped.") self._schedule_close() diff --git a/virtManager/connmanager.py b/virtManager/connmanager.py index 6ae4aff2..6e0eb453 100644 --- a/virtManager/connmanager.py +++ b/virtManager/connmanager.py @@ -3,7 +3,7 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging +from virtinst import log from .baseclass import vmmGObject from .connection import vmmConnection @@ -41,7 +41,7 @@ class vmmConnectionManager(vmmGObject): self.emit("conn-removed", uri) conn.cleanup() except Exception: - logging.exception("Error cleaning up conn=%s", uri) + log.exception("Error cleaning up conn=%s", uri) self._conns = {} @property diff --git a/virtManager/console.py b/virtManager/console.py index b17594eb..d7bb1f0c 100644 --- a/virtManager/console.py +++ b/virtManager/console.py @@ -5,11 +5,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gtk from gi.repository import Gdk +from virtinst import log + from .baseclass import vmmGObject, vmmGObjectUI from .serialcon import vmmSerialConsole from .sshtunnels import ConnectionInfo @@ -690,17 +690,17 @@ class vmmConsolePages(vmmGObjectUI): except Exception as e: # We can fail here if VM is destroyed: xen is a bit racy # and can't handle domain lookups that soon after - logging.exception("Getting graphics console failed: %s", str(e)) + log.exception("Getting graphics console failed: %s", str(e)) return if ginfo is None: - logging.debug("No graphics configured for guest") + log.debug("No graphics configured for guest") self._activate_unavailable_page( _("Graphical console not configured for guest")) return if ginfo.gtype not in self.config.embeddable_graphics(): - logging.debug("Don't know how to show graphics type '%s' " + log.debug("Don't know how to show graphics type '%s' " "disabling console page", ginfo.gtype) msg = (_("Cannot display graphical console type '%s'") @@ -712,7 +712,7 @@ class vmmConsolePages(vmmGObjectUI): self._activate_unavailable_page( _("Connecting to graphical console for guest")) - logging.debug("Starting connect process for %s", ginfo.logstring()) + log.debug("Starting connect process for %s", ginfo.logstring()) try: if ginfo.gtype == "vnc": viewer_class = VNCViewer @@ -731,7 +731,7 @@ class vmmConsolePages(vmmGObjectUI): self._viewer.console_open() except Exception as e: - logging.exception("Error connection to graphical console") + log.exception("Error connection to graphical console") self._activate_unavailable_page( _("Error connecting to graphical console") + ":\n%s" % e) @@ -818,7 +818,7 @@ class vmmConsolePages(vmmGObjectUI): if errdetails: msg += "\n" + errdetails if ssherr: - logging.debug("SSH tunnel error output: %s", ssherr) + log.debug("SSH tunnel error output: %s", ssherr) msg += "\n\n" msg += _("SSH tunnel error output: %s") % ssherr @@ -826,7 +826,7 @@ class vmmConsolePages(vmmGObjectUI): def _viewer_disconnected(self, ignore, errdetails, ssherr): self._activate_unavailable_page(_("Viewer disconnected.")) - logging.debug("Viewer disconnected") + log.debug("Viewer disconnected") # Make sure modifiers are set correctly self._viewer_focus_changed() @@ -835,7 +835,7 @@ class vmmConsolePages(vmmGObjectUI): self._refresh_resizeguest_from_settings() def _viewer_connected(self, ignore): - logging.debug("Viewer connected") + log.debug("Viewer connected") self._activate_viewer_page() # Make sure modifiers are set correctly diff --git a/virtManager/create.py b/virtManager/create.py index 5877a403..1e1d201d 100644 --- a/virtManager/create.py +++ b/virtManager/create.py @@ -5,7 +5,6 @@ # See the COPYING file in the top-level directory. import io -import logging import pkgutil import os import threading @@ -17,6 +16,7 @@ from gi.repository import Pango import virtinst import virtinst.generatename +from virtinst import log from . import uiutil from .addstorage import vmmAddStorage @@ -194,7 +194,7 @@ class vmmCreate(vmmGObjectUI): ########################### def show(self, parent, uri): - logging.debug("Showing new vm wizard") + log.debug("Showing new vm wizard") if not self.is_visible(): self._reset_state(uri) @@ -205,7 +205,7 @@ class vmmCreate(vmmGObjectUI): def _close(self, ignore1=None, ignore2=None): if self.is_visible(): - logging.debug("Closing new vm wizard") + log.debug("Closing new vm wizard") vmmEngine.get_instance().decrement_window_counter() self.topwin.hide() @@ -430,10 +430,10 @@ class vmmCreate(vmmGObjectUI): try: guest.set_uefi_path(guest.get_uefi_path()) installable_arch = True - logging.debug("UEFI found, setting it as default.") + log.debug("UEFI found, setting it as default.") except Exception as e: installable_arch = False - logging.debug("Error checking for UEFI default", exc_info=True) + log.debug("Error checking for UEFI default", exc_info=True) msg = _("Failed to setup UEFI: %s\n" "Install options are limited.") % e self._show_arch_warning(msg) @@ -659,7 +659,7 @@ class vmmCreate(vmmGObjectUI): try: self._populate_conn_state() except Exception as e: - logging.exception("Error setting create wizard conn state.") + log.exception("Error setting create wizard conn state.") return self._show_startup_error(str(e)) @@ -686,7 +686,7 @@ class vmmCreate(vmmGObjectUI): return self._capsinfo = capsinfo - logging.debug("Guest type set to os_type=%s, arch=%s, dom_type=%s", + log.debug("Guest type set to os_type=%s, arch=%s, dom_type=%s", self._capsinfo.os_type, self._capsinfo.arch, self._capsinfo.hypervisor_type) @@ -1080,7 +1080,7 @@ class vmmCreate(vmmGObjectUI): def _cleanup_disks_finished(error, details): if error: - logging.debug("Error cleaning up disk images:" + log.debug("Error cleaning up disk images:" "\nerror=%s\ndetails=%s", error, details) self.idle_add(self._close) @@ -1221,7 +1221,7 @@ class vmmCreate(vmmGObjectUI): path, ignore = self._get_storage_path(newname, do_log=False) self._populate_summary_storage(path=path) except Exception: - logging.debug("Error generating storage path on name change " + log.debug("Error generating storage path on name change " "for name=%s", newname, exc_info=True) @@ -1657,7 +1657,7 @@ class vmmCreate(vmmGObjectUI): ram = res.get_recommended_ram(self._guest.os.arch) n_cpus = res.get_recommended_ncpus(self._guest.os.arch) storage = res.get_recommended_storage(self._guest.os.arch) - logging.debug("Recommended resources for os=%s: " + log.debug("Recommended resources for os=%s: " "ram=%s ncpus=%s storage=%s", self._guest.osinfo.name, ram, n_cpus, storage) @@ -1720,12 +1720,12 @@ class vmmCreate(vmmGObjectUI): path = failed_disk.path path_already_created = failed_disk.storage_was_created if do_log: - logging.debug("Reusing failed disk path=%s " + log.debug("Reusing failed disk path=%s " "already_created=%s", path, path_already_created) else: path = self._addstorage.get_default_path(vmname) if do_log: - logging.debug("Default storage path is: %s", path) + log.debug("Default storage path is: %s", path) return path, path_already_created @@ -1771,7 +1771,7 @@ class vmmCreate(vmmGObjectUI): except Exception as e: return self.err.val_err(_("Invalid guest name"), str(e)) if self._is_default_storage(): - logging.debug("User changed VM name and using default " + log.debug("User changed VM name and using default " "storage, re-validating with new default storage path.") # User changed the name and we are using default storage # which depends on the VM name. Revalidate things @@ -1840,7 +1840,7 @@ class vmmCreate(vmmGObjectUI): def _do_start_detect_os(self, cdrom, location, forward_after_finish): self._detect_os_in_progress = False - logging.debug("Starting OS detection thread for cdrom=%s location=%s", + log.debug("Starting OS detection thread for cdrom=%s location=%s", cdrom, location) self.widget("create-forward").set_sensitive(False) @@ -1891,7 +1891,7 @@ class vmmCreate(vmmGObjectUI): distro = installer.detect_distro(self._guest) thread_results.set_distro(distro) except Exception: - logging.exception("Error detecting distro.") + log.exception("Error detecting distro.") thread_results.set_failed() def _report_detect_os_progress(self, idx, thread_results, @@ -1916,11 +1916,11 @@ class vmmCreate(vmmGObjectUI): distro = thread_results.get_distro() except Exception: distro = None - logging.exception("Error in distro detect timeout") + log.exception("Error in distro detect timeout") spin = self.widget("install-detect-os-spinner") spin.stop() - logging.debug("Finished UI OS detection.") + log.debug("Finished UI OS detection.") self.widget("create-forward").set_sensitive(True) self._os_already_detected_for_media = True @@ -1951,7 +1951,7 @@ class vmmCreate(vmmGObjectUI): if self._validate(page) is not True: return False - logging.debug("Starting create finish() sequence") + log.debug("Starting create finish() sequence") self._failed_guest = None guest = self._guest @@ -1967,7 +1967,7 @@ class vmmCreate(vmmGObjectUI): self._start_install(guest) return - logging.debug("User requested 'customize', launching dialog") + log.debug("User requested 'customize', launching dialog") self._show_customize_dialog(self._guest) except Exception as e: self.reset_finish_cursor() @@ -1989,12 +1989,12 @@ class vmmCreate(vmmGObjectUI): def customize_finished_cb(src, vdomain): if not self.is_visible(): return - logging.debug("User finished customize dialog, starting install") + log.debug("User finished customize dialog, starting install") self._failed_guest = None self._start_install(vdomain.get_backend()) def config_canceled_cb(src): - logging.debug("User closed customize window, closing wizard") + log.debug("User closed customize window, closing wizard") self._close_requested() # We specifically don't use vmmVMWindow.get_instance here since @@ -2085,9 +2085,9 @@ class vmmCreate(vmmGObjectUI): if poolname not in refresh_pools: refresh_pools.append(poolname) - logging.debug("Starting background install process") + log.debug("Starting background install process") guest.installer_instance.start_install(guest, meter=meter) - logging.debug("Install completed") + log.debug("Install completed") # Wait for VM to show up self.conn.schedule_priority_tick(pollvm=True) @@ -2127,7 +2127,7 @@ class vmmCreate(vmmGObjectUI): pool = self.conn.get_pool(poolname) self.idle_add(pool.refresh) except Exception: - logging.debug("Error looking up pool=%s for refresh after " + log.debug("Error looking up pool=%s for refresh after " "VM creation.", poolname, exc_info=True) @@ -2137,19 +2137,19 @@ class vmmCreate(vmmGObjectUI): to change, so we can restart it as needed """ if vm.is_crashed(): - logging.debug("VM crashed, cancelling install plans.") + log.debug("VM crashed, cancelling install plans.") return True if not vm.is_shutoff(): return if vm.get_install_abort(): - logging.debug("User manually shutdown VM, not restarting " + log.debug("User manually shutdown VM, not restarting " "guest after install.") return True try: - logging.debug("Install should be completed, starting VM.") + log.debug("Install should be completed, starting VM.") vm.startup() except Exception as e: self.err.show_err(_("Error continue install: %s") % str(e)) @@ -2162,6 +2162,7 @@ class vmmCreate(vmmGObjectUI): Call bootstrap method from virtBootstrap and show logger messages as state/details. """ + import logging import virtBootstrap meter.start(text=_("Bootstraping container"), size=100) @@ -2199,7 +2200,7 @@ class vmmCreate(vmmGObjectUI): kwargs['password'] = bootstrap_args['passwd'] if bootstrap_args['root_password']: kwargs['root_password'] = bootstrap_args['root_password'] - logging.debug('Start container bootstrap') + log.debug('Start container bootstrap') try: virtBootstrap.bootstrap(**kwargs) # Success - uncheck the 'install-oscontainer-bootstrap' checkbox diff --git a/virtManager/createnet.py b/virtManager/createnet.py index a774e734..c0b7dc66 100644 --- a/virtManager/createnet.py +++ b/virtManager/createnet.py @@ -5,7 +5,6 @@ # See the COPYING file in the top-level directory. import ipaddress -import logging from gi.repository import Gtk from gi.repository import Gdk @@ -14,6 +13,7 @@ from gi.repository import Pango import libvirt from virtinst import generatename +from virtinst import log from virtinst import Network from . import uiutil @@ -77,13 +77,13 @@ class vmmCreateNetwork(vmmGObjectUI): #################### def show(self, parent): - logging.debug("Showing new network wizard") + log.debug("Showing new network wizard") self.reset_state() self.topwin.set_transient_for(parent) self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing new network wizard") + log.debug("Closing new network wizard") self.topwin.hide() return 1 @@ -387,7 +387,7 @@ class vmmCreateNetwork(vmmGObjectUI): def _build_xmlobj_from_xmleditor(self): xml = self._xmleditor.get_xml() - logging.debug("Using XML from xmleditor:\n%s", xml) + log.debug("Using XML from xmleditor:\n%s", xml) return Network(self.conn.get_backend(), parsexml=xml) def _build_xmlobj_from_ui(self): @@ -464,7 +464,7 @@ class vmmCreateNetwork(vmmGObjectUI): def _async_net_create(self, asyncjob, net): ignore = asyncjob xml = net.get_xml() - logging.debug("Creating virtual network '%s' with xml:\n%s", + log.debug("Creating virtual network '%s' with xml:\n%s", net.name, xml) netobj = self.conn.get_backend().networkDefineXML(xml) diff --git a/virtManager/createpool.py b/virtManager/createpool.py index 9698ce08..0adbe0f9 100644 --- a/virtManager/createpool.py +++ b/virtManager/createpool.py @@ -4,12 +4,12 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os from gi.repository import Gdk from gi.repository import Gtk +from virtinst import log from virtinst import StoragePool from . import uiutil @@ -55,13 +55,13 @@ class vmmCreatePool(vmmGObjectUI): ####################### def show(self, parent): - logging.debug("Showing new pool wizard") + log.debug("Showing new pool wizard") self._reset_state() self.topwin.set_transient_for(parent) self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing new pool wizard") + log.debug("Closing new pool wizard") self.topwin.hide() return 1 @@ -195,7 +195,7 @@ class vmmCreatePool(vmmGObjectUI): pool_type, host=host) except Exception: - logging.exception("Pool enumeration failed") + log.exception("Pool enumeration failed") return plist @@ -343,7 +343,7 @@ class vmmCreatePool(vmmGObjectUI): def _build_xmlobj_from_xmleditor(self): xml = self._xmleditor.get_xml() - logging.debug("Using XML from xmleditor:\n%s", xml) + log.debug("Using XML from xmleditor:\n%s", xml) return StoragePool(self.conn.get_backend(), parsexml=xml) def _make_stub_pool(self): @@ -425,10 +425,10 @@ class vmmCreatePool(vmmGObjectUI): def _async_pool_create(self, asyncjob, pool, build): meter = asyncjob.get_meter() - logging.debug("Starting background pool creation.") + log.debug("Starting background pool creation.") poolobj = pool.install(create=True, meter=meter, build=build) poolobj.setAutostart(True) - logging.debug("Pool creation succeeded") + log.debug("Pool creation succeeded") def _finish(self): pool = self._build_xmlobj(check_xmleditor=True) diff --git a/virtManager/createvol.py b/virtManager/createvol.py index 6aa0ef04..6751e4bb 100644 --- a/virtManager/createvol.py +++ b/virtManager/createvol.py @@ -4,11 +4,10 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gtk from gi.repository import Gdk +from virtinst import log from virtinst import StorageVolume from . import uiutil @@ -61,17 +60,17 @@ class vmmCreateVolume(vmmGObjectUI): try: parent_xml = self._parent_pool.xmlobj.get_xml() except Exception: - logging.debug("Error getting parent_pool xml", exc_info=True) + log.debug("Error getting parent_pool xml", exc_info=True) parent_xml = None - logging.debug("Showing new volume wizard for parent_pool=\n%s", + log.debug("Showing new volume wizard for parent_pool=\n%s", parent_xml) self._reset_state() self.topwin.set_transient_for(parent) self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing new volume wizard") + log.debug("Closing new volume wizard") self.topwin.hide() if self._storage_browser: self._storage_browser.close() @@ -177,7 +176,7 @@ class vmmCreateVolume(vmmGObjectUI): if ret and suffix: ret = ret.rsplit(".", 1)[0] except Exception: - logging.exception("Error finding a default vol name") + log.exception("Error finding a default vol name") return ret @@ -254,7 +253,7 @@ class vmmCreateVolume(vmmGObjectUI): def _build_xmlobj_from_xmleditor(self): xml = self._xmleditor.get_xml() - logging.debug("Using XML from xmleditor:\n%s", xml) + log.debug("Using XML from xmleditor:\n%s", xml) return self._make_stub_vol(xml=xml) def _build_xmlobj_from_ui(self): @@ -336,9 +335,9 @@ class vmmCreateVolume(vmmGObjectUI): vol.pool = newpool meter = asyncjob.get_meter() - logging.debug("Starting background vol creation.") + log.debug("Starting background vol creation.") vol.install(meter=meter) - logging.debug("vol creation complete.") + log.debug("vol creation complete.") ################ diff --git a/virtManager/delete.py b/virtManager/delete.py index 794a1398..86d64960 100644 --- a/virtManager/delete.py +++ b/virtManager/delete.py @@ -7,13 +7,13 @@ import os import stat import traceback -import logging from gi.repository import Gtk from gi.repository import Gdk from gi.repository import Pango import virtinst +from virtinst import log from virtinst import xmlutil from .asyncjob import vmmAsyncJob @@ -63,14 +63,14 @@ class vmmDeleteDialog(vmmGObjectUI): prepare_storage_list(self.widget("delete-storage-list")) def show(self, parent, vm): - logging.debug("Showing delete wizard") + log.debug("Showing delete wizard") self._set_vm(vm) self.reset_state() self.topwin.set_transient_for(parent) self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing delete wizard") + log.debug("Closing delete wizard") self.topwin.hide() self._set_vm(None) return 1 @@ -170,7 +170,7 @@ class vmmDeleteDialog(vmmGObjectUI): try: if vm.is_active(): - logging.debug("Forcing VM '%s' power off.", vm.get_name()) + log.debug("Forcing VM '%s' power off.", vm.get_name()) vm.destroy() conn = vm.conn.get_backend() @@ -178,7 +178,7 @@ class vmmDeleteDialog(vmmGObjectUI): for path in paths: try: - logging.debug("Deleting path: %s", path) + log.debug("Deleting path: %s", path) meter.start(text=_("Deleting path '%s'") % path) self._async_delete_path(conn, path, meter) except Exception as e: @@ -187,7 +187,7 @@ class vmmDeleteDialog(vmmGObjectUI): meter.end(0) if undefine: - logging.debug("Removing VM '%s'", vm.get_name()) + log.debug("Removing VM '%s'", vm.get_name()) vm.delete() except Exception as e: @@ -225,7 +225,7 @@ class vmmDeleteDialog(vmmGObjectUI): try: vol = conn.storageVolLookupByPath(path) except Exception: - logging.debug("Path '%s' is not managed. Deleting locally", path) + log.debug("Path '%s' is not managed. Deleting locally", path) if vol: vol.delete(0) @@ -398,6 +398,6 @@ def do_we_default(conn, vm_name, vol, path, ro, shared, is_media): info = append_str(info, _("Storage is in use by the following " "virtual machines:\n- %s " % namestr)) except Exception as e: - logging.exception("Failed checking disk conflict: %s", str(e)) + log.exception("Failed checking disk conflict: %s", str(e)) return (not info, info) diff --git a/virtManager/details.py b/virtManager/details.py index 64f3f79f..b1202048 100644 --- a/virtManager/details.py +++ b/virtManager/details.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import re import traceback @@ -13,6 +12,7 @@ from gi.repository import Gtk import libvirt import virtinst +from virtinst import log from . import uiutil from .addhardware import vmmAddHardware @@ -692,7 +692,7 @@ class vmmDetails(vmmGObjectUI): machines = capsinfo.machines[:] except Exception: - logging.exception("Error determining machine list") + log.exception("Error determining machine list") show_machine = (arch not in ["i686", "x86_64"]) uiutil.set_grid_row_visible(self.widget("machine-type-title"), @@ -1923,7 +1923,7 @@ class vmmDetails(vmmGObjectUI): # Device removal def remove_device(self, devobj): - logging.debug("Removing device: %s", devobj) + log.debug("Removing device: %s", devobj) if not self.err.chkbox_helper(self.config.get_confirm_removedev, self.config.set_confirm_removedev, @@ -1943,7 +1943,7 @@ class vmmDetails(vmmGObjectUI): if self.vm.is_active(): self.vm.detach_device(devobj) except Exception as e: - logging.debug("Device could not be hotUNplugged: %s", str(e)) + log.debug("Device could not be hotUNplugged: %s", str(e)) detach_err = (str(e), "".join(traceback.format_exc())) if not detach_err: diff --git a/virtManager/domain.py b/virtManager/domain.py index f40b08e9..12d23c29 100644 --- a/virtManager/domain.py +++ b/virtManager/domain.py @@ -4,18 +4,18 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import time import threading import libvirt +from virtinst import DeviceController +from virtinst import DeviceDisk from virtinst import DomainCapabilities from virtinst import DomainSnapshot from virtinst import Guest -from virtinst import DeviceController -from virtinst import DeviceDisk +from virtinst import log from .libvirtobject import vmmLibvirtObject from .libvirtenummap import LibvirtEnumMap @@ -52,7 +52,7 @@ def start_job_progress_thread(vm, meter, progtext): progress = data_total - data_remaining meter.update(progress) except Exception: - logging.exception("Error calling jobinfo") + log.exception("Error calling jobinfo") return False return True @@ -154,7 +154,7 @@ class vmmDomainSnapshot(vmmLibvirtObject): def run_status_icon_name(self): status = self._state_str_to_int() if status not in LibvirtEnumMap.VM_STATUS_ICONS: - logging.debug("Unknown status %d, using NOSTATE", status) + log.debug("Unknown status %d, using NOSTATE", status) status = libvirt.VIR_DOMAIN_NOSTATE return LibvirtEnumMap.VM_STATUS_ICONS[status] @@ -338,7 +338,7 @@ class vmmDomain(vmmLibvirtObject): # attempt may result in a lookup failure. If device is present # in the active XML, assume all is good. if self.get_xmlobj().find_device(origdev): - logging.debug("Device in active config but not inactive config.") + log.debug("Device in active config but not inactive config.") return raise RuntimeError(_("Could not find specified device in the " @@ -386,7 +386,7 @@ class vmmDomain(vmmLibvirtObject): try: new_nvram.get_vol_object().delete(0) except Exception as warn: - logging.debug("rename failed and new nvram was not " + log.debug("rename failed and new nvram was not " "removed: '%s'", warn) raise error @@ -394,7 +394,7 @@ class vmmDomain(vmmLibvirtObject): try: old_nvram.get_vol_object().delete(0) except Exception as warn: - logging.debug("old nvram file was not removed: '%s'", warn) + log.debug("old nvram file was not removed: '%s'", warn) self.define_overview(nvram=new_nvram.path) @@ -916,7 +916,7 @@ class vmmDomain(vmmLibvirtObject): return devxml = devobj.get_xml() - logging.debug("attach_device with xml=\n%s", devxml) + log.debug("attach_device with xml=\n%s", devxml) self._backend.attachDevice(devxml) def detach_device(self, devobj): @@ -927,7 +927,7 @@ class vmmDomain(vmmLibvirtObject): return devxml = devobj.get_xml() - logging.debug("detach_device with xml=\n%s", devxml) + log.debug("detach_device with xml=\n%s", devxml) self._backend.detachDevice(devxml) def _update_device(self, devobj, flags=None): @@ -935,7 +935,7 @@ class vmmDomain(vmmLibvirtObject): flags = getattr(libvirt, "VIR_DOMAIN_DEVICE_MODIFY_LIVE", 1) xml = devobj.get_xml() - logging.debug("update_device with xml=\n%s", xml) + log.debug("update_device with xml=\n%s", xml) self._backend.updateDeviceFlags(xml, flags) def hotplug(self, vcpus=_SENTINEL, memory=_SENTINEL, maxmem=_SENTINEL, @@ -961,7 +961,7 @@ class vmmDomain(vmmLibvirtObject): self._backend.setVcpus(vcpus) if memory != _SENTINEL: - logging.debug("Hotplugging curmem=%s maxmem=%s for VM '%s'", + log.debug("Hotplugging curmem=%s maxmem=%s for VM '%s'", memory, maxmem, self.get_name()) actual_cur = self.get_memory() @@ -1053,7 +1053,7 @@ class vmmDomain(vmmLibvirtObject): if redefine: flags = (flags | libvirt.VIR_DOMAIN_SNAPSHOT_CREATE_REDEFINE) else: - logging.debug("Creating snapshot flags=%s xml=\n%s", flags, xml) + log.debug("Creating snapshot flags=%s xml=\n%s", flags, xml) self._backend.snapshotCreateXML(xml, flags) def refresh_interface_addresses(self, iface): @@ -1082,11 +1082,11 @@ class vmmDomain(vmmLibvirtObject): self._ip_cache["arp"] = self._get_interface_addresses(arp_flag) def _get_interface_addresses(self, source): - logging.debug("Calling interfaceAddresses source=%s", source) + log.debug("Calling interfaceAddresses source=%s", source) try: return self._backend.interfaceAddresses(source) except Exception as e: - logging.debug("interfaceAddresses failed: %s", str(e)) + log.debug("interfaceAddresses failed: %s", str(e)) return {} def get_interface_addresses(self, iface): @@ -1302,7 +1302,7 @@ class vmmDomain(vmmLibvirtObject): try: self._backend.undefineFlags(flags) except libvirt.libvirtError: - logging.exception("libvirt undefineFlags failed, " + log.exception("libvirt undefineFlags failed, " "falling back to old style") self._backend.undefine() @@ -1359,7 +1359,7 @@ class vmmDomain(vmmLibvirtObject): flags |= libvirt.VIR_MIGRATE_UNSAFE libvirt_destconn = destconn.get_backend().get_conn_for_api_arg() - logging.debug("Migrating: conn=%s flags=%s uri=%s tunnel=%s " + log.debug("Migrating: conn=%s flags=%s uri=%s tunnel=%s " "unsafe=%s temporary=%s", destconn, flags, dest_uri, tunnel, unsafe, temporary) @@ -1475,7 +1475,7 @@ class vmmDomain(vmmLibvirtObject): def run_status_icon_name(self): status = self.status() if status not in LibvirtEnumMap.VM_STATUS_ICONS: - logging.debug("Unknown status %s, using NOSTATE", status) + log.debug("Unknown status %s, using NOSTATE", status) status = libvirt.VIR_DOMAIN_NOSTATE return LibvirtEnumMap.VM_STATUS_ICONS[status] @@ -1573,7 +1573,7 @@ class vmmDomainVirtinst(vmmDomain): self._orig_backend = self._backend self._refresh_status() - logging.debug("%s initialized with XML=\n%s", self, self._XMLDesc(0)) + log.debug("%s initialized with XML=\n%s", self, self._XMLDesc(0)) def get_name(self): return self._backend.name @@ -1619,13 +1619,13 @@ class vmmDomainVirtinst(vmmDomain): return if origdisk.get_vol_object(): - logging.debug( + log.debug( "Syncing vol_object=%s from origdisk=%s to newdisk=%s", origdisk.get_vol_object(), origdisk, newdisk) newdisk.set_vol_object(origdisk.get_vol_object(), origdisk.get_parent_pool()) elif origdisk.get_vol_install(): - logging.debug( + log.debug( "Syncing vol_install=%s from origdisk=%s to newdisk=%s", origdisk.get_vol_install(), origdisk, newdisk) newdisk.set_vol_install(origdisk.get_vol_install()) diff --git a/virtManager/engine.py b/virtManager/engine.py index 564b44a8..f87d9755 100644 --- a/virtManager/engine.py +++ b/virtManager/engine.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import queue import threading @@ -14,6 +13,8 @@ from gi.repository import Gio from gi.repository import GLib from gi.repository import Gtk +from virtinst import log + from .baseclass import vmmGObject from .connect import vmmConnect from .connmanager import vmmConnectionManager @@ -109,9 +110,9 @@ class vmmEngine(vmmGObject): uris = list(self._connobjs.keys()) if not uris: - logging.debug("No stored URIs found.") + log.debug("No stored URIs found.") else: - logging.debug("Loading stored URIs:\n%s", + log.debug("Loading stored URIs:\n%s", " \n".join(sorted(uris))) if not skip_autostart: @@ -132,7 +133,7 @@ class vmmEngine(vmmGObject): """ manager = self._get_manager() - logging.debug("Trying to start libvirtd through systemd") + log.debug("Trying to start libvirtd through systemd") unitname = "libvirtd.service" libvirtd_installed = False libvirtd_active = False @@ -146,10 +147,10 @@ class vmmEngine(vmmGObject): "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", None) units = systemd.ListUnits() - logging.debug("Successfully listed units via systemd") + log.debug("Successfully listed units via systemd") except Exception: units = [] - logging.exception("Couldn't connect to systemd") + log.exception("Couldn't connect to systemd") libvirtd_installed = os.path.exists("/var/run/libvirt") libvirtd_active = os.path.exists("/var/run/libvirt/libvirt-sock") @@ -162,7 +163,7 @@ class vmmEngine(vmmGObject): unitpath = unitinfo[6] break - logging.debug("libvirtd_installed=%s libvirtd_active=%s unitpath=%s", + log.debug("libvirtd_installed=%s libvirtd_active=%s unitpath=%s", libvirtd_installed, libvirtd_active, unitpath) # If it's not running, try to start it @@ -177,14 +178,14 @@ class vmmEngine(vmmGObject): time.sleep(2) libvirtd_active = True except Exception: - logging.exception("Error starting libvirtd") + log.exception("Error starting libvirtd") if self.config.CLITestOptions.first_run: - logging.debug("--test-first-run, using uri=None to trigger error") + log.debug("--test-first-run, using uri=None to trigger error") tryuri = None else: tryuri = vmmConnect.default_uri() - logging.debug("Probed default URI=%s", tryuri) + log.debug("Probed default URI=%s", tryuri) # Manager fail message msg = "" @@ -249,7 +250,7 @@ class vmmEngine(vmmGObject): # Explicitly ignore connection errors, we've done that # for a while and it can be noisy if ConnectError is not None: - logging.debug("Autostart connection error: %s", + log.debug("Autostart connection error: %s", ConnectError.details) add_next_to_queue() @@ -281,7 +282,7 @@ class vmmEngine(vmmGObject): Invoked after application.run() """ if not self._application.get_windows(): - logging.debug("Initial gtkapplication activated") + log.debug("Initial gtkapplication activated") self._application.add_window(Gtk.Window()) def _init_gtk_application(self): @@ -314,7 +315,7 @@ class vmmEngine(vmmGObject): self._application.activate_action("cli_command", data) if is_remote: - logging.debug("Connected to remote app instance.") + log.debug("Connected to remote app instance.") return self._application.run(None) @@ -341,7 +342,7 @@ class vmmEngine(vmmGObject): def _add_obj_to_tick_queue(self, obj, isprio, **kwargs): if self._tick_queue.full(): if not self._tick_thread_slow: - logging.debug("Tick is slow, not running at requested rate.") + log.debug("Tick is slow, not running at requested rate.") self._tick_thread_slow = True return @@ -369,7 +370,7 @@ class vmmEngine(vmmGObject): # Don't attempt to show any UI error here, since it # can cause dialogs to appear from nowhere if say # libvirtd is shut down - logging.debug("Error polling connection %s", + log.debug("Error polling connection %s", conn.get_uri(), exc_info=True) # Need to clear reference to make leak check happy @@ -387,14 +388,14 @@ class vmmEngine(vmmGObject): Public function, called by toplevel windows """ self._window_count += 1 - logging.debug("window counter incremented to %s", self._window_count) + log.debug("window counter incremented to %s", self._window_count) def decrement_window_counter(self): """ Public function, called by toplevel windows """ self._window_count -= 1 - logging.debug("window counter decremented to %s", self._window_count) + log.debug("window counter decremented to %s", self._window_count) self._exit_app_if_no_windows() @@ -414,7 +415,7 @@ class vmmEngine(vmmGObject): if self._exiting: return if self._can_exit(): - logging.debug("No windows found, requesting app exit") + log.debug("No windows found, requesting app exit") self.exit_app() def exit_app(self): @@ -438,9 +439,9 @@ class vmmEngine(vmmGObject): objs.remove(self.object_key) for name in objs: - logging.debug("LEAK: %s", name) + log.debug("LEAK: %s", name) - logging.debug("Exiting app normally.") + log.debug("Exiting app normally.") finally: self._application.quit() @@ -499,7 +500,7 @@ class vmmEngine(vmmGObject): @_show_startup_error def _launch_cli_window(self, uri, show_window, clistr): - logging.debug("Launching requested window '%s'", show_window) + log.debug("Launching requested window '%s'", show_window) if show_window == self.CLI_SHOW_MANAGER: manager = self._get_manager() manager.set_initial_selection(uri) @@ -532,10 +533,10 @@ class vmmEngine(vmmGObject): show_window = variant[1] or self.CLI_SHOW_MANAGER domain = variant[2] - logging.debug("processing cli command uri=%s show_window=%s domain=%s", + log.debug("processing cli command uri=%s show_window=%s domain=%s", uri, show_window, domain) if not uri: - logging.debug("No cli action requested, launching default window") + log.debug("No cli action requested, launching default window") self._get_manager().show() return @@ -549,7 +550,7 @@ class vmmEngine(vmmGObject): def _open_completed(_c, ConnectError): if ConnectError: if conn_is_new: - logging.debug("Removing failed uri=%s", uri) + log.debug("Removing failed uri=%s", uri) vmmConnectionManager.get_instance().remove_conn(uri) self._handle_conn_error(conn, ConnectError) else: diff --git a/virtManager/error.py b/virtManager/error.py index c0d177d0..e54ca64a 100644 --- a/virtManager/error.py +++ b/virtManager/error.py @@ -3,12 +3,13 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import sys import traceback from gi.repository import Gtk +from virtinst import log + from .baseclass import vmmGObject @@ -80,7 +81,7 @@ class vmmErrorDialog(vmmGObject): if details.startswith(summary): det = details[len(summary):].strip() debugmsg += "\ndetails=%s" % det - logging.debug(debugmsg) + log.debug(debugmsg) # Make sure we have consistent details for error dialogs if (dialog_type == Gtk.MessageType.ERROR and summary not in details): @@ -124,7 +125,7 @@ class vmmErrorDialog(vmmGObject): logtext += " %s" % text2 if isinstance(text1, Exception) or isinstance(text2, Exception): - logging.exception(logtext) + log.exception(logtext) else: self._logtrace(logtext) diff --git a/virtManager/host.py b/virtManager/host.py index f3c65657..5ac130fc 100644 --- a/virtManager/host.py +++ b/virtManager/host.py @@ -4,7 +4,7 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging +from virtinst import log from . import uiutil from .baseclass import vmmGObjectUI @@ -84,7 +84,7 @@ class vmmHost(vmmGObjectUI): ####################### def show(self): - logging.debug("Showing host details: %s", self.conn) + log.debug("Showing host details: %s", self.conn) vis = self.is_visible() self.topwin.present() if vis: @@ -95,7 +95,7 @@ class vmmHost(vmmGObjectUI): def close(self, src=None, event=None): dummy = src dummy = event - logging.debug("Closing host window for %s", self.conn) + log.debug("Closing host window for %s", self.conn) if not self.is_visible(): return diff --git a/virtManager/hostnets.py b/virtManager/hostnets.py index 3cf7cc2a..4bdf5da0 100644 --- a/virtManager/hostnets.py +++ b/virtManager/hostnets.py @@ -4,11 +4,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gtk from gi.repository import Pango +from virtinst import log + from . import uiutil from .asyncjob import vmmAsyncJob from .baseclass import vmmGObjectUI @@ -166,7 +166,7 @@ class vmmHostNets(vmmGObjectUI): try: self._populate_net_state(net) except Exception as e: - logging.exception(e) + log.exception(e) self._set_error_page(_("Error selecting network: %s") % e) self._disable_net_apply() @@ -294,7 +294,7 @@ class vmmHostNets(vmmGObjectUI): if not result: return - logging.debug("Deleting network '%s'", net.get_name()) + log.debug("Deleting network '%s'", net.get_name()) vmmAsyncJob.simple_async_noshow(net.delete, [], self, _("Error deleting network '%s'") % net.get_name()) @@ -303,7 +303,7 @@ class vmmHostNets(vmmGObjectUI): if net is None: return - logging.debug("Starting network '%s'", net.get_name()) + log.debug("Starting network '%s'", net.get_name()) vmmAsyncJob.simple_async_noshow(net.start, [], self, _("Error starting network '%s'") % net.get_name()) @@ -312,12 +312,12 @@ class vmmHostNets(vmmGObjectUI): if net is None: return - logging.debug("Stopping network '%s'", net.get_name()) + log.debug("Stopping network '%s'", net.get_name()) vmmAsyncJob.simple_async_noshow(net.stop, [], self, _("Error stopping network '%s'") % net.get_name()) def _add_network_cb(self, src): - logging.debug("Launching 'Add Network'") + log.debug("Launching 'Add Network'") try: if self._addnet is None: self._addnet = vmmCreateNetwork(self.conn) @@ -335,7 +335,7 @@ class vmmHostNets(vmmGObjectUI): if net is None: return - logging.debug("Applying changes for network '%s'", net.get_name()) + log.debug("Applying changes for network '%s'", net.get_name()) try: if EDIT_NET_AUTOSTART in self._active_edits: auto = self.widget("net-autostart").get_active() diff --git a/virtManager/inspection.py b/virtManager/inspection.py index 09e6ce43..7762597a 100644 --- a/virtManager/inspection.py +++ b/virtManager/inspection.py @@ -3,10 +3,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import queue import threading +from virtinst import log + from .baseclass import vmmGObject from .connmanager import vmmConnectionManager from .domain import vmmInspectionApplication, vmmInspectionData @@ -34,13 +35,13 @@ class vmmInspection(vmmGObject): if cls._libguestfs_installed is None: try: import guestfs as ignore # pylint: disable=import-error - logging.debug("python guestfs is installed") + log.debug("python guestfs is installed") cls._libguestfs_installed = True except ImportError: - logging.debug("python guestfs is not installed") + log.debug("python guestfs is not installed") cls._libguestfs_installed = False except Exception: - logging.debug("error importing guestfs", + log.debug("error importing guestfs", exc_info=True) cls._libguestfs_installed = False return cls._libguestfs_installed @@ -56,7 +57,7 @@ class vmmInspection(vmmGObject): self._cached_data = {} val = self.config.get_libguestfs_inspect_vms() - logging.debug("libguestfs gsetting enabled=%s", str(val)) + log.debug("libguestfs gsetting enabled=%s", str(val)) if not val: return @@ -85,7 +86,7 @@ class vmmInspection(vmmGObject): # Called by the main thread whenever a VM is added to vmlist. def _vm_added(self, conn, connkey): if connkey.startswith("guestfs-"): - logging.debug("ignore libvirt/guestfs temporary VM %s", + log.debug("ignore libvirt/guestfs temporary VM %s", connkey) return @@ -93,7 +94,7 @@ class vmmInspection(vmmGObject): self._q.put(obj) def vm_refresh(self, vm): - logging.debug("Refresh requested for vm=%s", vm.get_name()) + log.debug("Refresh requested for vm=%s", vm.get_name()) obj = ("vm_refresh", vm.conn.get_uri(), vm.get_name(), vm.get_uuid()) self._q.put(obj) @@ -116,7 +117,7 @@ class vmmInspection(vmmGObject): while True: obj = self._q.get() if obj is None: - logging.debug("libguestfs queue obj=None, exiting thread") + log.debug("libguestfs queue obj=None, exiting thread") return self._process_queue_item(obj) self._q.task_done() @@ -173,7 +174,7 @@ class vmmInspection(vmmGObject): if vmuuid in self._cached_data: data = self._cached_data.get(vmuuid) if vm.inspection != data: - logging.debug("Found cached data for %s", prettyvm) + log.debug("Found cached data for %s", prettyvm) _set_vm_inspection_data(data) return @@ -181,7 +182,7 @@ class vmmInspection(vmmGObject): data = self._inspect_vm(conn, vm) except Exception as e: data = _inspection_error(_("Error inspection VM: %s") % str(e)) - logging.exception("%s: exception while processing", prettyvm) + log.exception("%s: exception while processing", prettyvm) _set_vm_inspection_data(data) @@ -203,17 +204,17 @@ class vmmInspection(vmmGObject): g.add_libvirt_dom(vm.get_backend(), readonly=1) g.launch() except Exception as e: - logging.debug("%s: Error launching libguestfs appliance: %s", + log.debug("%s: Error launching libguestfs appliance: %s", prettyvm, str(e)) return _inspection_error( _("Error launching libguestfs appliance: %s") % str(e)) - logging.debug("%s: inspection appliance connected", prettyvm) + log.debug("%s: inspection appliance connected", prettyvm) # Inspect the operating system. roots = g.inspect_os() if len(roots) == 0: - logging.debug("%s: no operating systems found", prettyvm) + log.debug("%s: no operating systems found", prettyvm) return _inspection_error( _("Inspection found no operating systems.")) @@ -247,7 +248,7 @@ class vmmInspection(vmmGObject): g.mount_ro(dev, mp) filesystems_mounted = True except Exception: - logging.exception("%s: exception mounting %s on %s " + log.exception("%s: exception mounting %s on %s " "(ignored)", prettyvm, dev, mp) @@ -285,21 +286,21 @@ class vmmInspection(vmmGObject): app.description = gapp["app2_description"] apps.append(app) except Exception: - logging.exception("%s: exception while listing apps (ignored)", + log.exception("%s: exception while listing apps (ignored)", prettyvm) # Force the libguestfs handle to close right now. del g # Log what we found. - logging.debug("%s: detected operating system: %s %s %d.%d (%s) (%s)", + log.debug("%s: detected operating system: %s %s %d.%d (%s) (%s)", prettyvm, os_type, distro, major_version, minor_version, product_name, package_format) - logging.debug("hostname: %s", hostname) + log.debug("hostname: %s", hostname) if icon: - logging.debug("icon: %d bytes", len(icon)) + log.debug("icon: %d bytes", len(icon)) if apps: - logging.debug("# apps: %d", len(apps)) + log.debug("# apps: %d", len(apps)) data = vmmInspectionData() data.os_type = str(os_type) diff --git a/virtManager/keyring.py b/virtManager/keyring.py index d8be8b0c..f15b61fb 100644 --- a/virtManager/keyring.py +++ b/virtManager/keyring.py @@ -4,11 +4,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gio from gi.repository import GLib +from virtinst import log + class vmmSecret(object): def __init__(self, name, secret=None, attributes=None): @@ -42,9 +42,9 @@ class vmmKeyring(object): "/org/freedesktop/secrets/aliases/default", "org.freedesktop.Secret.Collection", None) - logging.debug("Using keyring session %s", self._session) + log.debug("Using keyring session %s", self._session) except Exception: - logging.exception("Error determining keyring") + log.exception("Error determining keyring") ############## @@ -70,7 +70,7 @@ class vmmKeyring(object): props, params, replace)[0] ret = int(_id.rsplit("/")[-1]) except Exception: - logging.exception("Failed to add keyring secret") + log.exception("Failed to add keyring secret") return ret @@ -82,7 +82,7 @@ class vmmKeyring(object): "org.freedesktop.Secret.Item", None) iface.Delete("(s)", "/") except Exception: - logging.exception("Failed to delete keyring secret") + log.exception("Failed to delete keyring secret") def get_secret(self, _id): ret = None @@ -106,6 +106,6 @@ class vmmKeyring(object): ret = vmmSecret(label, secret, attrs) except Exception: - logging.exception("Failed to get keyring secret id=%s", _id) + log.exception("Failed to get keyring secret id=%s", _id) return ret diff --git a/virtManager/libvirtenummap.py b/virtManager/libvirtenummap.py index 71e4a5eb..d88efe11 100644 --- a/virtManager/libvirtenummap.py +++ b/virtManager/libvirtenummap.py @@ -3,11 +3,13 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import re import libvirt +from virtinst import log + + if not hasattr(libvirt, "VIR_DOMAIN_PMSUSPENDED"): setattr(libvirt, "VIR_DOMAIN_PMSUSPENDED", 7) @@ -84,7 +86,7 @@ class _LibvirtEnumMap(object): elif status == libvirt.VIR_DOMAIN_PMSUSPENDED: return _("Suspended") - logging.debug("Unknown status %s, returning 'Unknown'", status) + log.debug("Unknown status %s, returning 'Unknown'", status) return _("Unknown") @staticmethod @@ -142,11 +144,11 @@ class _LibvirtEnumMap(object): for key in [a for a in dir(libvirt) if re.match(regex, a)]: val = getattr(libvirt, key) if type(val) is not int: - logging.debug("libvirt regex=%s key=%s val=%s " + log.debug("libvirt regex=%s key=%s val=%s " "isn't an integer", regex, key, val) continue if val in ret: - logging.debug("libvirt regex=%s key=%s val=%s is already " + log.debug("libvirt regex=%s key=%s val=%s is already " "in dict as key=%s", regex, key, val, regex[val]) continue ret[val] = key diff --git a/virtManager/libvirtobject.py b/virtManager/libvirtobject.py index f61f08d4..136bf074 100644 --- a/virtManager/libvirtobject.py +++ b/virtManager/libvirtobject.py @@ -4,7 +4,7 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging +from virtinst import log from .baseclass import vmmGObject @@ -45,7 +45,7 @@ class vmmLibvirtObject(vmmGObject): @staticmethod def log_redefine_xml_diff(obj, origxml, newxml): if origxml == newxml: - logging.debug("Redefine requested for %s, but XML didn't change!", + log.debug("Redefine requested for %s, but XML didn't change!", obj) return @@ -54,7 +54,7 @@ class vmmLibvirtObject(vmmGObject): newxml.splitlines(1), fromfile="Original XML", tofile="New XML")) - logging.debug("Redefining %s with XML diff:\n%s", obj, diff) + log.debug("Redefining %s with XML diff:\n%s", obj, diff) @staticmethod def lifecycle_action(fn): @@ -121,7 +121,7 @@ class vmmLibvirtObject(vmmGObject): if xmlobj.name == newname: return - logging.debug("Changing %s name from %s to %s", + log.debug("Changing %s name from %s to %s", self, oldname, newname) origxml = xmlobj.get_xml() xmlobj.name = newname @@ -192,7 +192,7 @@ class vmmLibvirtObject(vmmGObject): try: self._init_libvirt_state() except Exception: - logging.debug("Error initializing libvirt state for %s", self, + log.debug("Error initializing libvirt state for %s", self, exc_info=True) initialize_failed = True @@ -276,11 +276,11 @@ class vmmLibvirtObject(vmmGObject): except Exception as e: # If we hit an exception here, it's often that the object # disappeared, so request the poll loop to be updated - logging.debug("Error refreshing %s from events: %s", self, e) + log.debug("Error refreshing %s from events: %s", self, e) poll_param = self._conn_tick_poll_param() if poll_param: kwargs = {"force": True, poll_param: True} - logging.debug("Scheduling priority tick with: %s", kwargs) + log.debug("Scheduling priority tick with: %s", kwargs) self.conn.schedule_priority_tick(**kwargs) def ensure_latest_xml(self, nosignal=False): diff --git a/virtManager/manager.py b/virtManager/manager.py index 2acc1a42..db806189 100644 --- a/virtManager/manager.py +++ b/virtManager/manager.py @@ -4,13 +4,12 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import GObject from gi.repository import Gtk from gi.repository import Gdk from gi.repository import GdkPixbuf +from virtinst import log from virtinst import xmlutil from . import vmmenu @@ -69,7 +68,7 @@ def _get_inspection_icon_pixbuf(vm, w, h): pb.close() return pb.get_pixbuf() except Exception: - logging.exception("Error loading inspection icon data") + log.exception("Error loading inspection icon data") vm.inspection.icon = None return None @@ -182,7 +181,7 @@ class vmmManager(vmmGObjectUI): if vis: return - logging.debug("Showing manager") + log.debug("Showing manager") if self.prev_position: self.topwin.move(*self.prev_position) self.prev_position = None @@ -193,7 +192,7 @@ class vmmManager(vmmGObjectUI): if not self.is_visible(): return - logging.debug("Closing manager") + log.debug("Closing manager") self.prev_position = self.topwin.get_position() self.topwin.hide() vmmEngine.get_instance().decrement_window_counter() diff --git a/virtManager/migrate.py b/virtManager/migrate.py index e27dca9f..27a89034 100644 --- a/virtManager/migrate.py +++ b/virtManager/migrate.py @@ -4,13 +4,13 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import traceback from gi.repository import Gdk from gi.repository import Gtk from gi.repository import Pango +from virtinst import log from virtinst import xmlutil from . import uiutil @@ -74,14 +74,14 @@ class vmmMigrateDialog(vmmGObjectUI): ############## def show(self, parent, vm): - logging.debug("Showing migrate wizard") + log.debug("Showing migrate wizard") self._set_vm(vm) self._reset_state() self.topwin.set_transient_for(parent) self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing migrate wizard") + log.debug("Closing migrate wizard") self.topwin.hide() self._set_vm(None) return 1 @@ -409,14 +409,14 @@ class vmmMigrateDialog(vmmGObjectUI): progWin.run() def _cancel_migration(self, asyncjob, vm): - logging.debug("Cancelling migrate job") + log.debug("Cancelling migrate job") if not vm: return try: vm.abort_job() except Exception as e: - logging.exception("Error cancelling migrate job") + log.exception("Error cancelling migrate job") asyncjob.show_warning(_("Error cancelling migrate job: %s") % e) return @@ -433,7 +433,7 @@ class vmmMigrateDialog(vmmGObjectUI): vminst = srcconn.get_backend().lookupByName(origvm.get_name()) vm = vmmDomain(srcconn, vminst, vminst.UUID()) - logging.debug("Migrating vm=%s from %s to %s", vm.get_name(), + log.debug("Migrating vm=%s from %s to %s", vm.get_name(), srcconn.get_uri(), dstconn.get_uri()) vm.migrate(dstconn, migrate_uri, tunnel, unsafe, temporary, diff --git a/virtManager/module_trace.py b/virtManager/module_trace.py index 95045990..7573a380 100644 --- a/virtManager/module_trace.py +++ b/virtManager/module_trace.py @@ -8,14 +8,14 @@ # python class or module. The trace output is logged using the regular # logging infrastructure. Invoke this with virt-manager --trace-libvirt -import logging import re import threading import time import traceback - from types import FunctionType +from virtinst import log + CHECK_MAINLOOP = False @@ -42,7 +42,7 @@ def generate_wrapper(origfunc, name): tb = "" if is_main_thread: tb = "\n%s" % "".join(traceback.format_stack()) - logging.debug("TRACE %s: thread=%s: %s %s %s%s", + log.debug("TRACE %s: thread=%s: %s %s %s%s", time.time(), threadname, name, args, kwargs, tb) return origfunc(*args, **kwargs) @@ -51,7 +51,7 @@ def generate_wrapper(origfunc, name): def wrap_func(module, funcobj): name = funcobj.__name__ - logging.debug("wrapfunc %s %s", funcobj, name) + log.debug("wrapfunc %s %s", funcobj, name) newfunc = generate_wrapper(funcobj, name) setattr(module, name, newfunc) @@ -60,14 +60,14 @@ def wrap_func(module, funcobj): def wrap_method(classobj, methodobj): name = methodobj.__name__ fullname = classobj.__name__ + "." + name - logging.debug("wrapmeth %s", fullname) + log.debug("wrapmeth %s", fullname) newfunc = generate_wrapper(methodobj, fullname) setattr(classobj, name, newfunc) def wrap_class(classobj): - logging.debug("wrapclas %s %s", classobj, classobj.__name__) + log.debug("wrapclas %s %s", classobj, classobj.__name__) for name in dir(classobj): obj = getattr(classobj, name) diff --git a/virtManager/netlist.py b/virtManager/netlist.py index 2fc72e4b..d827a5e9 100644 --- a/virtManager/netlist.py +++ b/virtManager/netlist.py @@ -4,11 +4,12 @@ # See the COPYING file in the top-level directory. import collections -import logging from gi.repository import Gtk import virtinst +from virtinst import log + from . import uiutil from .baseclass import vmmGObjectUI @@ -307,7 +308,7 @@ class vmmNetworkList(vmmGObjectUI): # Try to start the network try: netobj.start() - logging.debug("Started network '%s'", devname) + log.debug("Started network '%s'", devname) except Exception as e: return self.err.show_err(_("Could not start virtual network " "'%s': %s") % (devname, str(e))) diff --git a/virtManager/network.py b/virtManager/network.py index f8d041a2..a311411b 100644 --- a/virtManager/network.py +++ b/virtManager/network.py @@ -5,8 +5,8 @@ # See the COPYING file in the top-level directory. import ipaddress -import logging +from virtinst import log from virtinst import Network from .libvirtobject import vmmLibvirtObject @@ -98,7 +98,7 @@ class vmmNetwork(vmmLibvirtObject): try: self._leases = self._backend.DHCPLeases() except Exception as e: - logging.debug("Error getting %s DHCP leases: %s", self, str(e)) + log.debug("Error getting %s DHCP leases: %s", self, str(e)) self._leases = [] def get_dhcp_leases(self): diff --git a/virtManager/preferences.py b/virtManager/preferences.py index e55262ea..40bdf43f 100644 --- a/virtManager/preferences.py +++ b/virtManager/preferences.py @@ -4,12 +4,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gtk from gi.repository import Gdk from virtinst import DomainCpu +from virtinst import log from . import uiutil from .baseclass import vmmGObjectUI @@ -98,12 +97,12 @@ class vmmPreferences(vmmGObjectUI): self.bind_escape_key_close() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing preferences") + log.debug("Closing preferences") self.topwin.hide() return 1 def show(self, parent): - logging.debug("Showing preferences") + log.debug("Showing preferences") self.topwin.set_transient_for(parent) self.topwin.present() diff --git a/virtManager/serialcon.py b/virtManager/serialcon.py index 02976151..314e0746 100644 --- a/virtManager/serialcon.py +++ b/virtManager/serialcon.py @@ -4,20 +4,20 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - +# pylint: disable=wrong-import-order,ungrouped-imports import gi from gi.repository import Gdk from gi.repository import Gtk +from virtinst import log + # We can use either 2.91 or 2.90. This is just to silence runtime warnings -# pylint: disable=wrong-import-position try: gi.require_version("Vte", "2.91") - logging.debug("Using VTE API 2.91") + log.debug("Using VTE API 2.91") except ValueError: gi.require_version("Vte", "2.90") - logging.debug("Using VTE API 2.90") + log.debug("Using VTE API 2.90") from gi.repository import Vte import libvirt @@ -49,7 +49,7 @@ class ConsoleConnection(vmmGObject): if (events & libvirt.VIR_EVENT_HANDLE_ERROR or events & libvirt.VIR_EVENT_HANDLE_HANGUP): - logging.debug("Received stream ERROR/HANGUP, closing console") + log.debug("Received stream ERROR/HANGUP, closing console") self.close() return @@ -57,7 +57,7 @@ class ConsoleConnection(vmmGObject): try: got = self.stream.recv(1024 * 100) except Exception: - logging.exception("Error receiving stream data") + log.exception("Error receiving stream data") self.close() return @@ -65,7 +65,7 @@ class ConsoleConnection(vmmGObject): # This is basically EAGAIN return if len(got) == 0: - logging.debug("Received EOF from stream, closing") + log.debug("Received EOF from stream, closing") self.close() return @@ -80,7 +80,7 @@ class ConsoleConnection(vmmGObject): try: done = self.stream.send(self.terminalToStream.encode()) except Exception: - logging.exception("Error sending stream data") + log.exception("Error sending stream data") self.close() return @@ -104,7 +104,7 @@ class ConsoleConnection(vmmGObject): self.close() name = dev and dev.alias.name or None - logging.debug("Opening console stream for dev=%s alias=%s", + log.debug("Opening console stream for dev=%s alias=%s", dev, name) # libxl doesn't set aliases, their open_console just defaults to # opening the first console device, so don't force prescence of @@ -125,11 +125,11 @@ class ConsoleConnection(vmmGObject): try: self.stream.eventRemoveCallback() except Exception: - logging.exception("Error removing stream callback") + log.exception("Error removing stream callback") try: self.stream.finish() except Exception: - logging.exception("Error finishing stream") + log.exception("Error finishing stream") self.stream = None @@ -284,7 +284,7 @@ class vmmSerialConsole(vmmGObject): self.box.set_current_page(0) return True except Exception as e: - logging.exception("Error opening serial console") + log.exception("Error opening serial console") self.show_error(_("Error connecting to text console: %s") % e) try: self.console.close() @@ -307,12 +307,12 @@ class vmmSerialConsole(vmmGObject): if port == self.target_port: if path != self.lastpath: - logging.debug("Serial console '%s' path changed to %s", + log.debug("Serial console '%s' path changed to %s", self.target_port, path) self.lastpath = path return dev - logging.debug("No devices found for serial target port '%s'", + log.debug("No devices found for serial target port '%s'", self.target_port) self.lastpath = None return None diff --git a/virtManager/snapshots.py b/virtManager/snapshots.py index 8f46b2f6..762e967f 100644 --- a/virtManager/snapshots.py +++ b/virtManager/snapshots.py @@ -7,7 +7,6 @@ import datetime import glob import io -import logging import os from gi.repository import Gdk @@ -17,6 +16,7 @@ from gi.repository import Pango from virtinst import DomainSnapshot from virtinst import generatename +from virtinst import log from virtinst import xmlutil from . import uiutil @@ -60,7 +60,7 @@ def _mime_to_ext(val, reverse=False): return e if val == e and reverse: return m - logging.debug("Don't know how to convert %s=%s to %s", + log.debug("Don't know how to convert %s=%s to %s", reverse and "extension" or "mime", val, reverse and "mime" or "extension") @@ -91,13 +91,13 @@ class vmmSnapshotNew(vmmGObjectUI): ####################### def show(self, parent): - logging.debug("Showing new snapshot wizard") + log.debug("Showing new snapshot wizard") self._reset_state() self.topwin.set_transient_for(parent) self.topwin.present() def close(self, ignore1=None, ignore2=None): - logging.debug("Closing new snapshot wizard") + log.debug("Closing new snapshot wizard") self.topwin.hide() return 1 @@ -170,10 +170,10 @@ class vmmSnapshotNew(vmmGObjectUI): def _get_screenshot(self): if not self.vm.is_active(): - logging.debug("Skipping screenshot since VM is not active") + log.debug("Skipping screenshot since VM is not active") return if not self.vm.xmlobj.devices.graphics: - logging.debug("Skipping screenshot since VM has no graphics") + log.debug("Skipping screenshot since VM has no graphics") return try: @@ -184,7 +184,7 @@ class vmmSnapshotNew(vmmGObjectUI): self._take_screenshot() mime, sdata = self._take_screenshot() except Exception: - logging.exception("Error taking screenshot") + log.exception("Error taking screenshot") return ext = _mime_to_ext(mime) @@ -252,10 +252,10 @@ class vmmSnapshotNew(vmmGObjectUI): return filename = basesn + "." + _mime_to_ext(mime) - logging.debug("Writing screenshot to %s", filename) + log.debug("Writing screenshot to %s", filename) open(filename, "wb").write(sndata) except Exception: - logging.exception("Error saving screenshot") + log.exception("Error saving screenshot") def _create_new_snapshot(self): snap = self._validate_new_snapshot() @@ -443,7 +443,7 @@ class vmmSnapshotPage(vmmGObjectUI): try: snapshots = self.vm.list_snapshots() except Exception as e: - logging.exception(e) + log.exception(e) self._set_error_page(_("Error refreshing snapshot list: %s") % str(e)) return @@ -656,7 +656,7 @@ class vmmSnapshotPage(vmmGObjectUI): if not result: return - logging.debug("Running snapshot '%s'", snap.get_name()) + log.debug("Running snapshot '%s'", snap.get_name()) vmmAsyncJob.simple_async(self.vm.revert_to_snapshot, [snap], self, _("Running snapshot"), @@ -676,7 +676,7 @@ class vmmSnapshotPage(vmmGObjectUI): return for snap in snaps: - logging.debug("Deleting snapshot '%s'", snap.get_name()) + log.debug("Deleting snapshot '%s'", snap.get_name()) vmmAsyncJob.simple_async(snap.delete, [], self, _("Deleting snapshot"), _("Deleting snapshot '%s'") % snap.get_name(), @@ -700,5 +700,5 @@ class vmmSnapshotPage(vmmGObjectUI): try: self._set_snapshot_state(snap[0]) except Exception as e: - logging.exception(e) + log.exception(e) self._set_error_page(_("Error selecting snapshot: %s") % str(e)) diff --git a/virtManager/sshtunnels.py b/virtManager/sshtunnels.py index 8d19ccad..617b158c 100644 --- a/virtManager/sshtunnels.py +++ b/virtManager/sshtunnels.py @@ -4,7 +4,6 @@ # See the COPYING file in the top-level directory. import functools -import logging import os import queue import socket @@ -12,6 +11,8 @@ import signal import threading import ipaddress +from virtinst import log + from .baseclass import vmmGObject @@ -150,7 +151,7 @@ class _Tunnel(object): return self._closed = True - logging.debug("Close tunnel PID=%s ERRFD=%s", + log.debug("Close tunnel PID=%s ERRFD=%s", self._pid, self._errfd and self._errfd.fileno() or None) # Since this is a socket object, the file descriptor is closed @@ -197,7 +198,7 @@ class _Tunnel(object): self._errfd = errfds[0] self._errfd.setblocking(0) - logging.debug("Opened tunnel PID=%d ERRFD=%d", + log.debug("Opened tunnel PID=%d ERRFD=%d", pid, self._errfd.fileno()) self._pid = pid @@ -249,7 +250,7 @@ def _make_ssh_command(ginfo): argv.append("'%s'" % nc_cmd) argv_str = functools.reduce(lambda x, y: x + " " + y, argv[1:]) - logging.debug("Pre-generated ssh command for ginfo: %s", argv_str) + log.debug("Pre-generated ssh command for ginfo: %s", argv_str) return argv @@ -273,7 +274,7 @@ class SSHTunnels(object): _tunnel_scheduler.schedule(self._lock, t.open, self._sshcommand, sshfd) retfd = os.dup(viewerfd.fileno()) - logging.debug("Generated tunnel fd=%s for viewer", retfd) + log.debug("Generated tunnel fd=%s for viewer", retfd) return retfd def close_all(self): diff --git a/virtManager/statsmanager.py b/virtManager/statsmanager.py index e3b49d5d..26a08824 100644 --- a/virtManager/statsmanager.py +++ b/virtManager/statsmanager.py @@ -3,12 +3,13 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import re import time import libvirt +from virtinst import log + from .baseclass import vmmGObject @@ -203,17 +204,17 @@ class vmmStatsManager(vmmGObject): return rx, tx except libvirt.libvirtError as err: if vm.conn.support.is_error_nosupport(err): - logging.debug("conn does not support interfaceStats") + log.debug("conn does not support interfaceStats") self._net_stats_supported = False return 0, 0 - logging.debug("Error in interfaceStats for '%s' dev '%s': %s", + log.debug("Error in interfaceStats for '%s' dev '%s': %s", vm.get_name(), dev, err) if vm.is_active(): - logging.debug("Adding %s to skip list", dev) + log.debug("Adding %s to skip list", dev) statslist.stats_net_skip.append(dev) else: - logging.debug("Aren't running, don't add to skiplist") + log.debug("Aren't running, don't add to skiplist") return 0, 0 @@ -263,17 +264,17 @@ class vmmStatsManager(vmmGObject): return rd, wr except libvirt.libvirtError as err: if vm.conn.support.is_error_nosupport(err): - logging.debug("conn does not support blockStats") + log.debug("conn does not support blockStats") self._disk_stats_supported = False return 0, 0 - logging.debug("Error in blockStats for '%s' dev '%s': %s", + log.debug("Error in blockStats for '%s' dev '%s': %s", vm.get_name(), dev, err) if vm.is_active(): - logging.debug("Adding %s to skip list", dev) + log.debug("Adding %s to skip list", dev) statslist.stats_disk_skip.append(dev) else: - logging.debug("Aren't running, don't add to skiplist") + log.debug("Aren't running, don't add to skiplist") return 0, 0 @@ -304,7 +305,7 @@ class vmmStatsManager(vmmGObject): wr = io[3] return rd, wr except libvirt.libvirtError as e: - logging.debug("LXC style disk stats not supported: %s", e) + log.debug("LXC style disk stats not supported: %s", e) self._disk_stats_lxc_supported = False for disk in vm.get_disk_devices_norefresh(): @@ -341,7 +342,7 @@ class vmmStatsManager(vmmGObject): vm.get_backend().setMemoryStatsPeriod(secs, libvirt.VIR_DOMAIN_AFFECT_LIVE) except Exception as e: - logging.debug("Error setting memstats period: %s", e) + log.debug("Error setting memstats period: %s", e) def _old_mem_stats_helper(self, vm): totalmem = 1 @@ -352,10 +353,10 @@ class vmmStatsManager(vmmGObject): curmem = max(0, totalmem - stats.get("unused", totalmem)) except libvirt.libvirtError as err: if vm.conn.support.is_error_nosupport(err): - logging.debug("conn does not support memoryStats") + log.debug("conn does not support memoryStats") self._mem_stats_supported = False else: - logging.debug("Error reading mem stats: %s", err) + log.debug("Error reading mem stats: %s", err) return totalmem, curmem @@ -417,10 +418,10 @@ class vmmStatsManager(vmmGObject): ret[dom.UUIDString()] = domallstats except libvirt.libvirtError as err: if conn.support.is_error_nosupport(err): - logging.debug("conn does not support getAllDomainStats()") + log.debug("conn does not support getAllDomainStats()") self._all_stats_supported = False else: - logging.debug("Error call getAllDomainStats(): %s", err) + log.debug("Error call getAllDomainStats(): %s", err) return ret diff --git a/virtManager/storagebrowse.py b/virtManager/storagebrowse.py index d1924d94..7bf72507 100644 --- a/virtManager/storagebrowse.py +++ b/virtManager/storagebrowse.py @@ -4,7 +4,7 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging +from virtinst import log from . import uiutil from .baseclass import vmmGObjectUI @@ -33,7 +33,7 @@ class vmmStorageBrowser(vmmGObjectUI): def show(self, parent): - logging.debug("Showing storage browser") + log.debug("Showing storage browser") if not self._first_run: self._first_run = True pool = self.conn.get_default_pool() @@ -46,7 +46,7 @@ class vmmStorageBrowser(vmmGObjectUI): def close(self, ignore1=None, ignore2=None): if self.is_visible(): - logging.debug("Closing storage browser") + log.debug("Closing storage browser") self.topwin.hide() self.storagelist.close() return 1 @@ -116,7 +116,7 @@ class vmmStorageBrowser(vmmGObjectUI): def _volume_chosen(self, src, volume): ignore = src - logging.debug("Chosen volume XML:\n%s", volume.xmlobj.get_xml()) + log.debug("Chosen volume XML:\n%s", volume.xmlobj.get_xml()) self._finish(volume.get_target_path()) def _vol_sensitive_cb(self, fmt): @@ -145,7 +145,7 @@ class vmmStorageBrowser(vmmGObjectUI): dialog_type=dialog_type, browse_reason=self._browse_reason, dialog_name=dialog_name, choose_button=choose_button) if filename: - logging.debug("Browse local chose path=%s", filename) + log.debug("Browse local chose path=%s", filename) self._finish(filename) def _finish(self, path): diff --git a/virtManager/storagelist.py b/virtManager/storagelist.py index 414de035..1b61fb31 100644 --- a/virtManager/storagelist.py +++ b/virtManager/storagelist.py @@ -3,14 +3,13 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gdk from gi.repository import Gtk from gi.repository import Pango -from virtinst import StoragePool from virtinst import DeviceDisk +from virtinst import log +from virtinst import StoragePool from . import uiutil from .asyncjob import vmmAsyncJob @@ -364,7 +363,7 @@ class vmmStorageList(vmmGObjectUI): try: self._populate_pool_state(pool) except Exception as e: - logging.exception(e) + log.exception(e) self._set_error_page(_("Error selecting pool: %s") % e) self._disable_pool_apply() @@ -422,7 +421,7 @@ class vmmStorageList(vmmGObjectUI): sizestr = vol.get_pretty_capacity() fmt = vol.get_format() or "" except Exception: - logging.debug("Error getting volume info for '%s', " + log.debug("Error getting volume info for '%s', " "hiding it", key, exc_info=True) continue @@ -435,7 +434,7 @@ class vmmStorageList(vmmGObjectUI): if not namestr: namestr = None except Exception: - logging.exception("Failed to determine if storage volume in " + log.exception("Failed to determine if storage volume in " "use.") sensitive = True @@ -466,7 +465,7 @@ class vmmStorageList(vmmGObjectUI): if pool is None: return - logging.debug("Stopping pool '%s'", pool.get_name()) + log.debug("Stopping pool '%s'", pool.get_name()) vmmAsyncJob.simple_async_noshow(pool.stop, [], self, _("Error stopping pool '%s'") % pool.get_name()) @@ -475,12 +474,12 @@ class vmmStorageList(vmmGObjectUI): if pool is None: return - logging.debug("Starting pool '%s'", pool.get_name()) + log.debug("Starting pool '%s'", pool.get_name()) vmmAsyncJob.simple_async_noshow(pool.start, [], self, _("Error starting pool '%s'") % pool.get_name()) def _pool_add_cb(self, src): - logging.debug("Launching 'Add Pool' wizard") + log.debug("Launching 'Add Pool' wizard") try: if self._addpool is None: @@ -500,7 +499,7 @@ class vmmStorageList(vmmGObjectUI): if not result: return - logging.debug("Deleting pool '%s'", pool.get_name()) + log.debug("Deleting pool '%s'", pool.get_name()) vmmAsyncJob.simple_async_noshow(pool.delete, [], self, _("Error deleting pool '%s'") % pool.get_name()) @@ -511,7 +510,7 @@ class vmmStorageList(vmmGObjectUI): self._confirm_changes() - logging.debug("Refresh pool '%s'", pool.get_name()) + log.debug("Refresh pool '%s'", pool.get_name()) vmmAsyncJob.simple_async_noshow(pool.refresh, [], self, _("Error refreshing pool '%s'") % pool.get_name()) @@ -535,7 +534,7 @@ class vmmStorageList(vmmGObjectUI): if pool is None: return - logging.debug("Launching 'Add Volume' wizard for pool '%s'", + log.debug("Launching 'Add Volume' wizard for pool '%s'", pool.get_name()) try: if self._addvol is None: @@ -566,7 +565,7 @@ class vmmStorageList(vmmGObjectUI): pool.refresh() self.idle_add(idlecb) - logging.debug("Deleting volume '%s'", vol.get_name()) + log.debug("Deleting volume '%s'", vol.get_name()) vmmAsyncJob.simple_async_noshow(cb, [], self, _("Error deleting volume '%s'") % vol.get_name()) @@ -580,7 +579,7 @@ class vmmStorageList(vmmGObjectUI): if pool is None: return - logging.debug("Applying changes for pool '%s'", pool.get_name()) + log.debug("Applying changes for pool '%s'", pool.get_name()) try: if EDIT_POOL_AUTOSTART in self._active_edits: auto = self.widget("pool-autostart").get_active() diff --git a/virtManager/storagepool.py b/virtManager/storagepool.py index 69ba877b..e3c25018 100644 --- a/virtManager/storagepool.py +++ b/virtManager/storagepool.py @@ -4,9 +4,9 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import time +from virtinst import log from virtinst import pollhelpers from virtinst import StoragePool, StorageVolume @@ -39,7 +39,7 @@ class vmmStorageVolume(vmmLibvirtObject): try: return self._backend.XMLDesc(flags) except Exception as e: - logging.debug("XMLDesc for vol=%s failed: %s", + log.debug("XMLDesc for vol=%s failed: %s", self._backend.key(), e) raise diff --git a/virtManager/systray.py b/virtManager/systray.py index 70e0a063..f3dcf2bd 100644 --- a/virtManager/systray.py +++ b/virtManager/systray.py @@ -4,12 +4,12 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os from gi.repository import Gio from gi.repository import Gtk +from virtinst import log from virtinst import xmlutil from . import vmmenu @@ -61,18 +61,18 @@ def _has_appindicator_dbus(): return True return False except Exception: - logging.exception("Error checking for appindicator dbus") + log.exception("Error checking for appindicator dbus") return False _USING_APPINDICATOR = False if AppIndicator3: if not _has_appindicator_dbus(): - logging.debug("AppIndicator3 is available, but didn't " + log.debug("AppIndicator3 is available, but didn't " "find any dbus watcher.") else: _USING_APPINDICATOR = True - logging.debug("Using AppIndicator3 for systray") + log.debug("Using AppIndicator3 for systray") ########################### @@ -210,7 +210,7 @@ class vmmSystray(vmmGObject): def _show_systray_changed_cb(self): do_show = self.config.get_view_system_tray() - logging.debug("Showing systray: %s", do_show) + log.debug("Showing systray: %s", do_show) if do_show: self._show_systray() diff --git a/virtManager/viewers.py b/virtManager/viewers.py index 8b0eab5e..657ca8b8 100644 --- a/virtManager/viewers.py +++ b/virtManager/viewers.py @@ -5,7 +5,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import socket from gi.repository import Gdk @@ -22,6 +21,8 @@ try: except (ValueError, ImportError): have_spice_gtk = False +from virtinst import log + from .baseclass import vmmGObject from .sshtunnels import SSHTunnels @@ -329,7 +330,7 @@ class VNCViewer(Viewer): self.emit("size-allocate", None) def _auth_failure_cb(self, ignore, msg): - logging.debug("VNC auth failure. msg=%s", msg) + log.debug("VNC auth failure. msg=%s", msg) self.emit("auth-error", msg, True) def _auth_credential(self, src_ignore, credList): @@ -353,7 +354,7 @@ class VNCViewer(Viewer): withUsername = False withPassword = False for cred in values: - logging.debug("Got credential request %s", cred) + log.debug("Got credential request %s", cred) if cred == GtkVnc.DisplayCredential.PASSWORD: withPassword = True elif cred == GtkVnc.DisplayCredential.USERNAME: @@ -398,14 +399,14 @@ class VNCViewer(Viewer): try: keys = [int(k) for k in keys.split(',')] except Exception: - logging.debug("Error in grab_keys configuration in Gsettings", + log.debug("Error in grab_keys configuration in Gsettings", exc_info=True) return seq = GtkVnc.GrabSequence.new(keys) self._display.set_grab_keys(seq) except Exception as e: - logging.debug("Error when getting the grab keys combination: %s", + log.debug("Error when getting the grab keys combination: %s", str(e)) def _send_keys(self, keys): @@ -449,11 +450,11 @@ class VNCViewer(Viewer): host, port, ignore = self._ginfo.get_conn_host() if not self._ginfo.gsocket: - logging.debug("VNC connecting to host=%s port=%s", host, port) + log.debug("VNC connecting to host=%s port=%s", host, port) self._display.open_host(host, port) return - logging.debug("VNC connecting to socket=%s", self._ginfo.gsocket) + log.debug("VNC connecting to socket=%s", self._ginfo.gsocket) try: sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) sock.connect(self._ginfo.gsocket) @@ -538,7 +539,7 @@ class SpiceViewer(Viewer): gtk_session.set_property("auto-usbredir", True) except Exception: self._usbdev_manager = None - logging.debug("Error initializing spice usb device manager", + log.debug("Error initializing spice usb device manager", exc_info=True) @@ -553,11 +554,11 @@ class SpiceViewer(Viewer): self._emit_disconnected() elif event == SpiceClientGLib.ChannelEvent.ERROR_AUTH: if not self._spice_session.get_property("password"): - logging.debug("Spice channel received ERROR_AUTH, but no " + log.debug("Spice channel received ERROR_AUTH, but no " "password set, assuming it wants credentials.") self.emit("need-auth", True, False) else: - logging.debug("Spice channel received ERROR_AUTH, but a " + log.debug("Spice channel received ERROR_AUTH, but a " "password is already set. Assuming authentication failed.") self.emit("auth-error", channel.get_error().message, False) elif "ERROR" in str(event): @@ -568,7 +569,7 @@ class SpiceViewer(Viewer): error = None if channel.get_error(): error = channel.get_error().message - logging.debug("Spice channel event=%s message=%s", event, error) + log.debug("Spice channel event=%s message=%s", event, error) msg = _("Encountered SPICE %(error-name)s") % { "error-name": event.value_nick} @@ -589,7 +590,7 @@ class SpiceViewer(Viewer): # are still rolling in return - logging.debug("Requesting fd for channel: %s", channel) + log.debug("Requesting fd for channel: %s", channel) channel.connect_after("channel-event", self._fd_channel_event_cb) fd = self._get_fd_for_open() @@ -614,7 +615,7 @@ class SpiceViewer(Viewer): channel_id = channel.get_property("channel-id") if channel_id != 0: - logging.debug("Spice multi-head unsupported") + log.debug("Spice multi-head unsupported") return self._display_channel = channel @@ -664,14 +665,14 @@ class SpiceViewer(Viewer): try: keys = [int(k) for k in keys.split(',')] except Exception: - logging.debug("Error in grab_keys configuration in Gsettings", + log.debug("Error in grab_keys configuration in Gsettings", exc_info=True) return seq = SpiceClientGtk.GrabSequence.new(keys) self._display.set_grab_keys(seq) except Exception as e: - logging.debug("Error when getting the grab keys combination: %s", + log.debug("Error when getting the grab keys combination: %s", str(e)) def _send_keys(self, keys): @@ -698,7 +699,7 @@ class SpiceViewer(Viewer): host, port, tlsport = self._ginfo.get_conn_host() self._create_spice_session() - logging.debug("Spice connecting to host=%s port=%s tlsport=%s", + log.debug("Spice connecting to host=%s port=%s tlsport=%s", host, port, tlsport) self._spice_session.set_property("host", str(host)) if port: diff --git a/virtManager/vmmenu.py b/virtManager/vmmenu.py index a5b283d0..a5b4410f 100644 --- a/virtManager/vmmenu.py +++ b/virtManager/vmmenu.py @@ -4,10 +4,10 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gtk +from virtinst import log + from .asyncjob import vmmAsyncJob @@ -159,14 +159,14 @@ class VMActionUI(object): @staticmethod def save_cancel(asyncjob, vm): - logging.debug("Cancelling save job") + log.debug("Cancelling save job") if not vm: return try: vm.abort_job() except Exception as e: - logging.exception("Error cancelling save job") + log.exception("Error cancelling save job") asyncjob.show_warning(_("Error cancelling save job: %s") % str(e)) return @@ -209,7 +209,7 @@ class VMActionUI(object): "shutting down the OS and may cause data loss.")): return - logging.debug("Destroying vm '%s'", vm.get_name()) + log.debug("Destroying vm '%s'", vm.get_name()) vmmAsyncJob.simple_async_noshow(vm.destroy, [], src, _("Error shutting down domain")) @@ -221,19 +221,19 @@ class VMActionUI(object): vm.get_name())): return - logging.debug("Pausing vm '%s'", vm.get_name()) + log.debug("Pausing vm '%s'", vm.get_name()) vmmAsyncJob.simple_async_noshow(vm.suspend, [], src, _("Error pausing domain")) @staticmethod def resume(src, vm): - logging.debug("Unpausing vm '%s'", vm.get_name()) + log.debug("Unpausing vm '%s'", vm.get_name()) vmmAsyncJob.simple_async_noshow(vm.resume, [], src, _("Error unpausing domain")) @staticmethod def run(src, vm): - logging.debug("Starting vm '%s'", vm.get_name()) + log.debug("Starting vm '%s'", vm.get_name()) if vm.has_managed_save(): def errorcb(error, details): @@ -278,7 +278,7 @@ class VMActionUI(object): vm.get_name())): return - logging.debug("Shutting down vm '%s'", vm.get_name()) + log.debug("Shutting down vm '%s'", vm.get_name()) vmmAsyncJob.simple_async_noshow(vm.shutdown, [], src, _("Error shutting down domain")) @@ -290,7 +290,7 @@ class VMActionUI(object): vm.get_name())): return - logging.debug("Rebooting vm '%s'", vm.get_name()) + log.debug("Rebooting vm '%s'", vm.get_name()) vmmAsyncJob.simple_async_noshow(vm.reboot, [], src, _("Error rebooting domain")) @@ -305,7 +305,7 @@ class VMActionUI(object): "shutting down the OS and may cause data loss.")): return - logging.debug("Resetting vm '%s'", vm.get_name()) + log.debug("Resetting vm '%s'", vm.get_name()) vmmAsyncJob.simple_async_noshow(vm.reset, [], src, _("Error resetting domain")) diff --git a/virtManager/vmwindow.py b/virtManager/vmwindow.py index 02520f1c..6377c105 100644 --- a/virtManager/vmwindow.py +++ b/virtManager/vmwindow.py @@ -4,11 +4,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging - from gi.repository import Gdk from gi.repository import Gtk +from virtinst import log + from . import vmmenu from .baseclass import vmmGObjectUI from .details import vmmDetails @@ -174,7 +174,7 @@ class vmmVMWindow(vmmGObjectUI): self.vm = None def show(self): - logging.debug("Showing VM details: %s", self.vm) + log.debug("Showing VM details: %s", self.vm) vis = self.is_visible() self.topwin.present() if vis: @@ -194,15 +194,15 @@ class vmmVMWindow(vmmGObjectUI): self.cleanup() def _customize_cancel(self): - logging.debug("Asking to cancel customization") + log.debug("Asking to cancel customization") result = self.err.yes_no( _("This will abort the installation. Are you sure?")) if not result: - logging.debug("Customize cancel aborted") + log.debug("Customize cancel aborted") return - logging.debug("Canceling customization") + log.debug("Canceling customization") return self._close() def _customize_cancel_clicked(self, src): @@ -214,7 +214,7 @@ class vmmVMWindow(vmmGObjectUI): def close(self, ignore1=None, ignore2=None): if self.is_visible(): - logging.debug("Closing VM details: %s", self.vm) + log.debug("Closing VM details: %s", self.vm) return self._close() def _close(self): @@ -230,7 +230,7 @@ class vmmVMWindow(vmmGObjectUI): try: self.console.details_close_viewer() except Exception: - logging.error("Failure when disconnecting from desktop server") + log.error("Failure when disconnecting from desktop server") self.emit("closed") vmmEngine.get_instance().decrement_window_counter() @@ -535,7 +535,7 @@ class vmmVMWindow(vmmGObjectUI): browse_reason=self.config.CONFIG_DIR_SCREENSHOT, default_name=default) if not path: - logging.debug("No screenshot path given, skipping save.") + log.debug("No screenshot path given, skipping save.") return filename = path diff --git a/virtconv/formats.py b/virtconv/formats.py index 0bc7c4d8..435a9eb8 100644 --- a/virtconv/formats.py +++ b/virtconv/formats.py @@ -7,13 +7,13 @@ # See the COPYING file in the top-level directory. # -import logging import os import re import shutil import subprocess import tempfile +from virtinst import log from virtinst import StoragePool @@ -74,15 +74,15 @@ def _run_cmd(cmd): """ Return the exit status and output to stdout and stderr. """ - logging.debug("Running command: %s", " ".join(cmd)) + log.debug("Running command: %s", " ".join(cmd)) proc = subprocess.Popen(cmd, stderr=subprocess.PIPE, stdout=subprocess.PIPE, close_fds=True) stdout, stderr = proc.communicate() ret = proc.wait() - logging.debug("stdout=%s", stdout) - logging.debug("stderr=%s", stderr) + log.debug("stdout=%s", stdout) + log.debug("stderr=%s", stderr) if ret == 0: return @@ -199,7 +199,7 @@ class VirtConverter(object): parser = _find_parser_by_name(input_name) input_file = os.path.abspath(input_file) - logging.debug("converter __init__ with input=%s parser=%s", + log.debug("converter __init__ with input=%s parser=%s", input_file, parser) (self._input_file, @@ -207,7 +207,7 @@ class VirtConverter(object): self._force_clean) = _find_input(input_file, parser, self.print_cb) self._top_dir = os.path.dirname(os.path.abspath(self._input_file)) - logging.debug("converter not input_file=%s parser=%s", + log.debug("converter not input_file=%s parser=%s", self._input_file, self.parser) self._guest = self.parser.export_libvirt(self.conn, @@ -296,7 +296,7 @@ class VirtConverter(object): continue if disk_format and disk.driver_type == disk_format: - logging.debug("path=%s is already in requested format=%s", + log.debug("path=%s is already in requested format=%s", disk.path, disk_format) disk_format = None diff --git a/virtconv/ovf.py b/virtconv/ovf.py index 24151151..12b64028 100644 --- a/virtconv/ovf.py +++ b/virtconv/ovf.py @@ -5,11 +5,11 @@ # See the COPYING file in the top-level directory. # -import logging import os import xml.etree.ElementTree import virtinst +from virtinst import log from .formats import parser_class @@ -184,7 +184,7 @@ def _import_file(conn, input_file): if any([p for p in parsed_sections if p in env_node.tag]): continue - logging.debug("Unhandled XML section '%s'", + log.debug("Unhandled XML section '%s'", env_node.tag) if not _convert_bool_val(env_node.attrib.get("required")): @@ -274,11 +274,11 @@ class ovf_parser(parser_class): root = xml.etree.ElementTree.parse(input_file).getroot() return root.tag == ("{%s}Envelope" % OVF_NAMESPACES["ovf"]) except Exception: - logging.debug("Error parsing OVF XML", exc_info=True) + log.debug("Error parsing OVF XML", exc_info=True) return False @staticmethod def export_libvirt(conn, input_file): - logging.debug("Importing OVF XML:\n%s", open(input_file).read()) + log.debug("Importing OVF XML:\n%s", open(input_file).read()) return _import_file(conn, input_file) diff --git a/virtconv/vmx.py b/virtconv/vmx.py index 242e01e3..3b0d73e9 100644 --- a/virtconv/vmx.py +++ b/virtconv/vmx.py @@ -8,12 +8,12 @@ # import collections -import logging import os import re import shlex import virtinst +from virtinst import log from virtinst import xmlutil from .formats import parser_class @@ -92,10 +92,10 @@ def parse_vmdk(filename): # Detect if passed file is a descriptor file # Assume descriptor isn't larger than 10K if not os.path.exists(filename): - logging.debug("VMDK file '%s' doesn't exist", filename) + log.debug("VMDK file '%s' doesn't exist", filename) return if os.path.getsize(filename) > (10 * 1024): - logging.debug("VMDK file '%s' too big to be a descriptor", filename) + log.debug("VMDK file '%s' too big to be a descriptor", filename) return f = open(filename, "r") @@ -105,7 +105,7 @@ def parse_vmdk(filename): try: vmdkfile = _VMXFile(content) except Exception: - logging.exception("%s looked like a vmdk file, but parsing failed", + log.exception("%s looked like a vmdk file, but parsing failed", filename) return @@ -202,7 +202,7 @@ def parse_disk_entry(conn, disks, fullkey, value, topdir): # See if the filename is actually a VMDK descriptor file newpath = parse_vmdk(os.path.join(topdir, disk.path)) if newpath: - logging.debug("VMDK file parsed path %s->%s", + log.debug("VMDK file parsed path %s->%s", disk.path, newpath) disk.path = newpath @@ -243,7 +243,7 @@ class vmx_parser(parser_class): infile = open(input_file, "r") contents = infile.readlines() infile.close() - logging.debug("Importing VMX file:\n%s", "".join(contents)) + log.debug("Importing VMX file:\n%s", "".join(contents)) vmxfile = _VMXFile(contents) config = vmxfile.pairs() diff --git a/virtinst/__init__.py b/virtinst/__init__.py index 51183268..7403924d 100644 --- a/virtinst/__init__.py +++ b/virtinst/__init__.py @@ -64,3 +64,5 @@ from virtinst.cloner import Cloner from virtinst.snapshot import DomainSnapshot from virtinst.connection import VirtinstConnection + +from virtinst.logger import log diff --git a/virtinst/capabilities.py b/virtinst/capabilities.py index 5b7e855a..d8250daa 100644 --- a/virtinst/capabilities.py +++ b/virtinst/capabilities.py @@ -6,10 +6,10 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import pwd from .domain import DomainCpu +from .logger import log from .xmlbuilder import XMLBuilder, XMLChildProperty, XMLProperty @@ -88,7 +88,7 @@ class _CapsHost(XMLBuilder): user = pwd.getpwuid(uid)[0] return user, uid except Exception: # pragma: no cover - logging.debug("Exception parsing qemu dac baselabel=%s", + log.debug("Exception parsing qemu dac baselabel=%s", label, exc_info=True) return None, None # pragma: no cover diff --git a/virtinst/cli.py b/virtinst/cli.py index 1a9b1d88..cc13af20 100644 --- a/virtinst/cli.py +++ b/virtinst/cli.py @@ -8,8 +8,6 @@ import argparse import collections -import logging -import logging.handlers import os import re import shlex @@ -25,6 +23,7 @@ from .buildconfig import BuildConfig from .connection import VirtinstConnection from .devices import (Device, DeviceController, DeviceDisk, DeviceGraphics, DeviceInterface, DevicePanic) +from .logger import log from .nodedev import NodeDevice from .osdict import OSDB from .storage import StoragePool, StorageVolume @@ -116,6 +115,7 @@ def setupParser(usage, description, introspection_epilog=False): def earlyLogging(): + import logging logging.basicConfig(level=logging.DEBUG, format='%(message)s') @@ -145,7 +145,7 @@ def setupLogging(appname, debug_stdout, do_quiet, cli_app=True): not os.access(logfile, os.W_OK)): raise RuntimeError("No write access to logfile %s" % logfile) except Exception as e: # pragma: no cover - logging.warning("Error setting up logfile: %s", e) + log.warning("Error setting up logfile: %s", e) logfile = None dateFormat = "%a, %d %b %Y %H:%M:%S" @@ -153,19 +153,24 @@ def setupLogging(appname, debug_stdout, do_quiet, cli_app=True): "%(levelname)s (%(module)s:%(lineno)d) %(message)s") streamErrorFormat = "%(levelname)-8s %(message)s" + import logging + import logging.handlers rootLogger = logging.getLogger() # Undo early logging for handler in rootLogger.handlers: rootLogger.removeHandler(handler) + # Undo any logging on our log handler. Needed for test suite + for handler in log.handlers: + log.removeHandler(handler) - rootLogger.setLevel(logging.DEBUG) + log.setLevel(logging.DEBUG) if logfile: fileHandler = logging.handlers.RotatingFileHandler( logfile, "ae", 1024 * 1024, 5) fileHandler.setFormatter( logging.Formatter(fileFormat, dateFormat)) - rootLogger.addHandler(fileHandler) + log.addHandler(fileHandler) streamHandler = logging.StreamHandler(sys.stderr) if debug_stdout: @@ -184,11 +189,11 @@ def setupLogging(appname, debug_stdout, do_quiet, cli_app=True): streamHandler = None if streamHandler: - rootLogger.addHandler(streamHandler) + log.addHandler(streamHandler) # Log uncaught exceptions def exception_log(typ, val, tb): # pragma: no cover - logging.debug("Uncaught exception:\n%s", + log.debug("Uncaught exception:\n%s", "".join(traceback.format_exception(typ, val, tb))) if not debug_stdout: # If we are already logging to stdout, don't double print @@ -196,10 +201,8 @@ def setupLogging(appname, debug_stdout, do_quiet, cli_app=True): sys.__excepthook__(typ, val, tb) sys.excepthook = exception_log - logging.getLogger("requests").setLevel(logging.ERROR) - # Log the app command string - logging.debug("Launched with command line: %s", " ".join(sys.argv)) + log.debug("Launched with command line: %s", " ".join(sys.argv)) def in_testsuite(): @@ -215,10 +218,10 @@ def getConnection(uri, conn=None): # preopened connection passed in via test suite return conn - logging.debug("Requesting libvirt URI %s", (uri or "default")) + log.debug("Requesting libvirt URI %s", (uri or "default")) conn = VirtinstConnection(uri) conn.open(_openauth_cb, None) - logging.debug("Received libvirt URI %s", conn.uri) + log.debug("Received libvirt URI %s", conn.uri) return conn @@ -230,9 +233,9 @@ def _openauth_cb(creds, _cbdata): noecho = credtype in [ libvirt.VIR_CRED_PASSPHRASE, libvirt.VIR_CRED_NOECHOPROMPT] if not prompt: - logging.error("No prompt for auth credtype=%s", credtype) + log.error("No prompt for auth credtype=%s", credtype) return -1 - logging.debug("openauth_cb prompt=%s", prompt) + log.debug("openauth_cb prompt=%s", prompt) prompt += ": " if noecho: @@ -254,22 +257,22 @@ def fail(msg, do_exit=True): """ Convenience function when failing in cli app """ - logging.debug("".join(traceback.format_stack())) - logging.error(msg) + log.debug("".join(traceback.format_stack())) + log.error(msg) if sys.exc_info()[0] is not None: - logging.debug("", exc_info=True) + log.debug("", exc_info=True) if do_exit: _fail_exit() def print_stdout(msg, do_force=False): - logging.debug(msg) + log.debug(msg) if do_force or not get_global_state().quiet: print(msg) def print_stderr(msg): - logging.debug(msg) + log.debug(msg) print(msg, file=sys.stderr) @@ -295,14 +298,14 @@ def install_fail(guest): def set_prompt(prompt): # Set whether we allow prompts, or fail if a prompt pops up if prompt: - logging.warning("--prompt mode is no longer supported.") + log.warning("--prompt mode is no longer supported.") def check_path_search(conn, path): searchdata = DeviceDisk.check_path_search(conn, path) if not searchdata.fixlist: return - logging.warning(_("%s may not be accessible by the hypervisor. " + log.warning(_("%s may not be accessible by the hypervisor. " "You will need to grant the '%s' user search permissions for " "the following directories: %s"), path, searchdata.user, searchdata.fixlist) # pragma: no cover @@ -315,10 +318,10 @@ def validate_disk(dev, warn_overwrite=False): fail(msg + (_(" (Use --check %s=off or " "--check all=off to override)") % checkname)) - logging.debug("Skipping --check %s error condition '%s'", + log.debug("Skipping --check %s error condition '%s'", checkname, msg) if warn_on_skip: - logging.warning(msg) + log.warning(msg) def check_path_exists(dev): """ @@ -361,7 +364,7 @@ def validate_disk(dev, warn_overwrite=False): def _run_console(domain, args): ignore = domain - logging.debug("Running: %s", " ".join(args)) + log.debug("Running: %s", " ".join(args)) if in_testsuite(): print_stdout("testsuite console command: %s" % args) args = ["/bin/true"] @@ -385,7 +388,7 @@ def _gfx_console(guest, domain): if guest.has_gl() or guest.has_listen_none(): args.append("--attach") - logging.debug("Launching virt-viewer for graphics type '%s'", + log.debug("Launching virt-viewer for graphics type '%s'", guest.devices.graphics[0].type) return _run_console(domain, args) @@ -395,7 +398,7 @@ def _txt_console(guest, domain): "--connect", guest.conn.uri, "console", guest.name] - logging.debug("Connecting to text console") + log.debug("Connecting to text console") return _run_console(domain, args) @@ -415,10 +418,10 @@ def connect_console(guest, domain, consolecb, wait, destroy_on_exit): try: os.waitpid(child, 0) except OSError as e: # pragma: no cover - logging.debug("waitpid error: %s", e) + log.debug("waitpid error: %s", e) if destroy_on_exit and domain.isActive(): - logging.debug("console exited and destroy_on_exit passed, destroying") + log.debug("console exited and destroy_on_exit passed, destroying") domain.destroy() @@ -431,20 +434,20 @@ def get_console_cb(guest): if gtype not in ["default", DeviceGraphics.TYPE_VNC, DeviceGraphics.TYPE_SPICE]: - logging.debug("No viewer to launch for graphics type '%s'", gtype) + log.debug("No viewer to launch for graphics type '%s'", gtype) return if not in_testsuite(): try: subprocess.check_output(["virt-viewer", "--version"]) except OSError: - logging.warning(_("Unable to connect to graphical console: " + log.warning(_("Unable to connect to graphical console: " "virt-viewer not installed. Please install " "the 'virt-viewer' package.")) return None if not os.environ.get("DISPLAY", ""): - logging.warning(_("Graphics requested but DISPLAY is not set. " + log.warning(_("Graphics requested but DISPLAY is not set. " "Not running virt-viewer.")) return None @@ -1451,7 +1454,7 @@ class VirtCLIParser(metaclass=_InitClass): ret += xmlutil.listify(objs) except Exception as e: - logging.debug("Exception parsing inst=%s optstr=%s", + log.debug("Exception parsing inst=%s optstr=%s", inst, self.optstr, exc_info=True) fail(_("Error: %(cli_flag_name)s %(options)s: %(err)s") % {"cli_flag_name": self.cli_flag_name(), @@ -1482,7 +1485,7 @@ class VirtCLIParser(metaclass=_InitClass): ret.append(inst) self._check_leftover_opts(optdict) except Exception as e: - logging.debug("Exception parsing inst=%s optstr=%s", + log.debug("Exception parsing inst=%s optstr=%s", inst, self.optstr, exc_info=True) fail(_("Error: %(cli_flag_name)s %(options)s: %(err)s") % {"cli_flag_name": self.cli_flag_name(), @@ -2881,7 +2884,7 @@ class ParserDisk(VirtCLIParser): raise ValueError(_("Storage volume must be specified as " "vol=poolname/volname")) poolname, volname = volname.split("/") - logging.debug("Parsed --disk volume as: pool=%s vol=%s", + log.debug("Parsed --disk volume as: pool=%s vol=%s", poolname, volname) super()._parse(inst) @@ -3198,14 +3201,14 @@ class ParserGraphics(VirtCLIParser): if inst.conn.is_qemu() and inst.gl: if inst.type != "spice": - logging.warning("graphics type=%s does not support GL", inst.type) + log.warning("graphics type=%s does not support GL", inst.type) elif not inst.conn.support.conn_spice_gl(): - logging.warning("qemu/libvirt version may not support spice GL") + log.warning("qemu/libvirt version may not support spice GL") if inst.conn.is_qemu() and inst.rendernode: if inst.type != "spice": - logging.warning("graphics type=%s does not support rendernode", inst.type) + log.warning("graphics type=%s does not support rendernode", inst.type) elif not inst.conn.support.conn_spice_rendernode(): - logging.warning("qemu/libvirt version may not support rendernode") + log.warning("qemu/libvirt version may not support rendernode") return ret diff --git a/virtinst/cloner.py b/virtinst/cloner.py index 6d3a6001..ac6987b0 100644 --- a/virtinst/cloner.py +++ b/virtinst/cloner.py @@ -7,7 +7,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import re import os @@ -19,6 +18,7 @@ from . import xmlutil from .guest import Guest from .devices import DeviceInterface from .devices import DeviceDisk +from .logger import log from .storage import StorageVolume from .devices import DeviceChannel @@ -132,7 +132,7 @@ class Cloner(object): disk.validate() disklist.append(disk) except Exception as e: - logging.debug("Error setting clone path.", exc_info=True) + log.debug("Error setting clone path.", exc_info=True) raise ValueError(_("Could not use path '%s' for cloning: %s") % (path, str(e))) @@ -251,7 +251,7 @@ class Cloner(object): """ Validate and setup all parameters needed for the original (cloned) VM """ - logging.debug("Validating original guest parameters") + log.debug("Validating original guest parameters") if self.original_guest is None and self.original_xml is None: raise RuntimeError(_("Original guest name or xml is required.")) @@ -261,7 +261,7 @@ class Cloner(object): flags = libvirt.VIR_DOMAIN_XML_SECURE self.original_xml = self.original_dom.XMLDesc(flags) - logging.debug("Original XML:\n%s", self.original_xml) + log.debug("Original XML:\n%s", self.original_xml) self._guest = Guest(self.conn, parsexml=self.original_xml) self._guest.id = None @@ -269,9 +269,9 @@ class Cloner(object): # Pull clonable storage info from the original xml self._original_disks = self._get_original_disks_info() - logging.debug("Original paths: %s", + log.debug("Original paths: %s", [d.path for d in self.original_disks]) - logging.debug("Original sizes: %s", + log.debug("Original sizes: %s", [d.get_size() for d in self.original_disks]) # If domain has devices to clone, it must be 'off' or 'paused' @@ -373,7 +373,7 @@ class Cloner(object): """ Validate and set up all parameters needed for the new (clone) VM """ - logging.debug("Validating clone parameters.") + log.debug("Validating clone parameters.") self._clone_xml = self.original_xml @@ -383,14 +383,14 @@ class Cloner(object): {"passed": len(self.clone_disks), "need": len(self.original_disks)}) - logging.debug("Clone paths: %s", [d.path for d in self.clone_disks]) + log.debug("Clone paths: %s", [d.path for d in self.clone_disks]) self._guest.name = self._clone_name self._guest.uuid = self._clone_uuid self._clone_macs.reverse() for dev in self._guest.devices.graphics: if dev.port and dev.port != -1: - logging.warning(_("Setting the graphics device port to autoport, " + log.warning(_("Setting the graphics device port to autoport, " "in order to avoid conflicting.")) dev.port = -1 @@ -434,14 +434,14 @@ class Cloner(object): # Save altered clone xml self._clone_xml = self._guest.get_xml() - logging.debug("Clone guest xml is\n%s", self._clone_xml) + log.debug("Clone guest xml is\n%s", self._clone_xml) def start_duplicate(self, meter=None): """ Actually perform the duplication: cloning disks if needed and defining the new clone xml. """ - logging.debug("Starting duplicate.") + log.debug("Starting duplicate.") meter = progress.ensure_meter(meter) dom = None @@ -459,12 +459,12 @@ class Cloner(object): if self._nvram_disk: self._nvram_disk.build_storage(meter) except Exception as e: - logging.debug("Duplicate failed: %s", str(e)) + log.debug("Duplicate failed: %s", str(e)) if dom: dom.undefine() raise - logging.debug("Duplicating finished.") + log.debug("Duplicating finished.") def generate_clone_disk_path(self, origpath, newname=None): origname = self.original_guest @@ -555,7 +555,7 @@ class Cloner(object): raise ValueError(_("Disk path '%s' does not exist.") % newd.path) except Exception as e: - logging.debug("Exception creating clone disk objects", + log.debug("Exception creating clone disk objects", exc_info=True) raise ValueError(_("Could not determine original disk " "information: %s" % str(e))) diff --git a/virtinst/connection.py b/virtinst/connection.py index c851b45d..0a008e2c 100644 --- a/virtinst/connection.py +++ b/virtinst/connection.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import weakref @@ -14,6 +13,7 @@ from . import pollhelpers from . import support from . import Capabilities from .guest import Guest +from .logger import log from .nodedev import NodeDevice from .storage import StoragePool, StorageVolume from .uri import URI, MagicURI @@ -248,7 +248,7 @@ class VirtinstConnection(object): xml = vol.XMLDesc(0) ret.append(StorageVolume(weakref.proxy(self), parsexml=xml)) except Exception as e: - logging.debug("Fetching volume XML failed: %s", e) + log.debug("Fetching volume XML failed: %s", e) return ret def _fetch_all_vols_raw(self): @@ -342,7 +342,7 @@ class VirtinstConnection(object): try: self._daemon_version = self._libvirtconn.getLibVersion() except Exception: - logging.debug("Error calling getLibVersion", exc_info=True) + log.debug("Error calling getLibVersion", exc_info=True) return self._daemon_version def conn_version(self): @@ -354,7 +354,7 @@ class VirtinstConnection(object): try: self._conn_version = self._libvirtconn.getVersion() except Exception: - logging.debug("Error calling getVersion", exc_info=True) + log.debug("Error calling getVersion", exc_info=True) return self._conn_version diff --git a/virtinst/devices/disk.py b/virtinst/devices/disk.py index 60861268..2d864899 100644 --- a/virtinst/devices/disk.py +++ b/virtinst/devices/disk.py @@ -6,7 +6,7 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging +from ..logger import log from .. import diskbackend from .. import progress @@ -221,7 +221,7 @@ class DeviceDisk(Device): "path '%s'. Use libvirt APIs to manage the parent directory " "as a pool first.") % volname) - logging.debug("Creating volume '%s' on pool '%s'", + log.debug("Creating volume '%s' on pool '%s'", volname, poolobj.name()) cap = (size * 1024 * 1024 * 1024) @@ -347,15 +347,15 @@ class DeviceDisk(Device): self._set_default_storage_backend() def set_vol_object(self, vol_object, parent_pool): - logging.debug("disk.set_vol_object: volxml=\n%s", + log.debug("disk.set_vol_object: volxml=\n%s", vol_object.XMLDesc(0)) - logging.debug("disk.set_vol_object: poolxml=\n%s", + log.debug("disk.set_vol_object: poolxml=\n%s", parent_pool.XMLDesc(0)) self._change_backend(None, vol_object, parent_pool) self._set_xmlpath(self.path) def set_vol_install(self, vol_install): - logging.debug("disk.set_vol_install: name=%s poolxml=\n%s", + log.debug("disk.set_vol_install: name=%s poolxml=\n%s", vol_install.name, vol_install.pool.XMLDesc(0)) self._storage_backend = diskbackend.ManagedStorageCreator( self.conn, vol_install) @@ -678,7 +678,7 @@ class DeviceDisk(Device): self.source_volume) except Exception as e: self._source_volume_err = str(e) - logging.debug("Error fetching source pool=%s vol=%s", + log.debug("Error fetching source pool=%s vol=%s", self.source_pool, self.source_volume, exc_info=True) if vol_object is None and path is None: diff --git a/virtinst/devices/graphics.py b/virtinst/devices/graphics.py index faf4eabc..2472cc77 100644 --- a/virtinst/devices/graphics.py +++ b/virtinst/devices/graphics.py @@ -4,10 +4,10 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os from .device import Device +from ..logger import log from ..xmlbuilder import XMLBuilder, XMLChildProperty, XMLProperty @@ -218,9 +218,9 @@ class DeviceGraphics(Device): def _default_type(self, guest): gtype = guest.default_graphics_type - logging.debug("Using default_graphics=%s", gtype) + log.debug("Using default_graphics=%s", gtype) if gtype == "spice" and not self._spice_supported(): - logging.debug("spice requested but HV doesn't support it. " + log.debug("spice requested but HV doesn't support it. " "Using vnc.") gtype = "vnc" return gtype @@ -229,7 +229,7 @@ class DeviceGraphics(Device): if self.type != "spice": return None if not self.conn.is_remote(): - logging.debug("Local connection, disabling spice image " + log.debug("Local connection, disabling spice image " "compression.") return "off" return None diff --git a/virtinst/devices/interface.py b/virtinst/devices/interface.py index 0e014a8d..db36b2af 100644 --- a/virtinst/devices/interface.py +++ b/virtinst/devices/interface.py @@ -4,11 +4,11 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import random from .device import Device +from ..logger import log from ..xmlbuilder import XMLBuilder, XMLChildProperty, XMLProperty @@ -42,13 +42,13 @@ def _random_mac(conn): def _default_route(): route_file = "/proc/net/route" if not os.path.exists(route_file): # pragma: no cover - logging.debug("route_file=%s does not exist", route_file) + log.debug("route_file=%s does not exist", route_file) return None for line in open(route_file): info = line.split() if len(info) != 11: # pragma: no cover - logging.debug("Unexpected field count=%s when parsing %s", + log.debug("Unexpected field count=%s when parsing %s", len(info), route_file) break @@ -135,7 +135,7 @@ class DeviceInterface(Device): except RuntimeError: # pragma: no cover continue - logging.debug( # pragma: no cover + log.debug( # pragma: no cover "Failed to generate non-conflicting MAC") return None # pragma: no cover diff --git a/virtinst/diskbackend.py b/virtinst/diskbackend.py index a6c8dc33..fa3f3a0f 100644 --- a/virtinst/diskbackend.py +++ b/virtinst/diskbackend.py @@ -6,7 +6,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import re import stat @@ -14,6 +13,7 @@ import subprocess import libvirt +from .logger import log from .storage import StoragePool, StorageVolume @@ -139,7 +139,7 @@ def manage_path(conn, path): if not poolname: poolname = "dirpool" poolname = StoragePool.find_free_name(conn, poolname) - logging.debug("Attempting to build pool=%s target=%s", poolname, dirname) + log.debug("Attempting to build pool=%s target=%s", poolname, dirname) poolxml = StoragePool(conn) poolxml.name = poolname @@ -252,16 +252,16 @@ def _fix_perms_acl(dirname, username): stderr=subprocess.PIPE) out, err = proc.communicate() - logging.debug("Ran command '%s'", cmd) + log.debug("Ran command '%s'", cmd) if out or err: - logging.debug("out=%s\nerr=%s", out, err) + log.debug("out=%s\nerr=%s", out, err) if proc.returncode != 0: raise ValueError(err) def _fix_perms_chmod(dirname): - logging.debug("Setting +x on %s", dirname) + log.debug("Setting +x on %s", dirname) mode = os.stat(dirname).st_mode newmode = mode | stat.S_IXOTH os.chmod(dirname, newmode) @@ -281,8 +281,8 @@ def set_dirs_searchable(dirlist, username): _fix_perms_acl(dirname, username) continue except Exception as e: - logging.debug("setfacl failed: %s", e) - logging.debug("trying chmod") + log.debug("setfacl failed: %s", e) + log.debug("trying chmod") useacl = False try: @@ -324,11 +324,11 @@ def _is_dir_searchable(dirname, uid, username): stderr=subprocess.PIPE) out, err = proc.communicate() except OSError: - logging.debug("Didn't find the getfacl command.") + log.debug("Didn't find the getfacl command.") return False if proc.returncode != 0: - logging.debug("Cmd '%s' failed: %s", cmd, err) + log.debug("Cmd '%s' failed: %s", cmd, err) return False pattern = "user:%s:..x" % username @@ -475,7 +475,7 @@ class _StorageCreator(_StorageBase): if err: raise ValueError(msg) if msg: - logging.warning(msg) + log.warning(msg) def will_create_storage(self): return True @@ -544,10 +544,10 @@ class CloneStorageCreator(_StorageCreator): if self._input_path == "/dev/null": # Not really sure why this check is here, # but keeping for compat - logging.debug("Source dev was /dev/null. Skipping") + log.debug("Source dev was /dev/null. Skipping") return if self._input_path == self._output_path: - logging.debug("Source and destination are the same. Skipping.") + log.debug("Source and destination are the same. Skipping.") return # If a destination file exists and sparse flag is True, @@ -568,7 +568,7 @@ class CloneStorageCreator(_StorageCreator): clone_block_size = 1024 * 1024 * 10 sparse = False - logging.debug("Local Cloning %s to %s, sparse=%s, block_size=%s", + log.debug("Local Cloning %s to %s, sparse=%s, block_size=%s", self._input_path, self._output_path, sparse, clone_block_size) diff --git a/virtinst/domain/cpu.py b/virtinst/domain/cpu.py index a288848f..5fb3d226 100644 --- a/virtinst/domain/cpu.py +++ b/virtinst/domain/cpu.py @@ -4,7 +4,7 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging +from ..logger import log from ..xmlbuilder import XMLBuilder, XMLProperty, XMLChildProperty @@ -152,7 +152,7 @@ class DomainCpu(XMLBuilder): break def set_model(self, guest, val): - logging.debug("setting cpu model %s", val) + log.debug("setting cpu model %s", val) if val: self.mode = "custom" if not self.match: @@ -179,7 +179,7 @@ class DomainCpu(XMLBuilder): """ domcaps = guest.lookup_domcaps() if domcaps.supports_safe_host_model(): - logging.debug("Using domcaps for host-copy") + log.debug("Using domcaps for host-copy") cpu = domcaps.cpu.get_mode("host-model") model = cpu.models[0].model fallback = cpu.models[0].fallback @@ -284,7 +284,7 @@ class DomainCpu(XMLBuilder): if cpu_model and cpu_model.usable != "no": return - logging.debug("Host capabilities CPU '%s' is not supported " + log.debug("Host capabilities CPU '%s' is not supported " "according to domain capabilities. Unsetting CPU model", self.model) self.model = None diff --git a/virtinst/domcapabilities.py b/virtinst/domcapabilities.py index 302ed8c7..f11f18aa 100644 --- a/virtinst/domcapabilities.py +++ b/virtinst/domcapabilities.py @@ -6,13 +6,13 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import re import xml.etree.ElementTree as ET import libvirt from .domain import DomainCpu +from .logger import log from .xmlbuilder import XMLBuilder, XMLChildProperty, XMLProperty @@ -158,7 +158,7 @@ class DomainCapabilities(XMLBuilder): xml = conn.getDomainCapabilities(emulator, arch, machine, hvtype) except Exception: - logging.debug("Error fetching domcapabilities XML", + log.debug("Error fetching domcapabilities XML", exc_info=True) if not xml: @@ -271,7 +271,7 @@ class DomainCapabilities(XMLBuilder): def _get_expanded_cpu(self, mode): cpuXML = self._convert_mode_to_cpu(mode.get_xml()) - logging.debug("CPU XML for security flag baseline: %s", cpuXML) + log.debug("CPU XML for security flag baseline: %s", cpuXML) try: expandedXML = self.conn.baselineHypervisorCPU( @@ -281,7 +281,7 @@ class DomainCapabilities(XMLBuilder): expandedXML = self.conn.baselineCPU([cpuXML], libvirt.VIR_CONNECT_BASELINE_CPU_EXPAND_FEATURES) - logging.debug("Expanded CPU XML: %s", expandedXML) + log.debug("Expanded CPU XML: %s", expandedXML) return DomainCpu(self.conn, expandedXML) @@ -307,7 +307,7 @@ class DomainCapabilities(XMLBuilder): try: cpu = self._get_expanded_cpu(m) except libvirt.libvirtError as e: - logging.warning(_("Failed to get expanded CPU XML: %s"), e) + log.warning(_("Failed to get expanded CPU XML: %s"), e) break for feature in cpu.features: diff --git a/virtinst/guest.py b/virtinst/guest.py index e5b140b8..441c38cf 100644 --- a/virtinst/guest.py +++ b/virtinst/guest.py @@ -6,7 +6,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import random import libvirt @@ -17,6 +16,7 @@ from .buildconfig import BuildConfig from .devices import * # pylint: disable=wildcard-import from .domain import * # pylint: disable=wildcard-import from .domcapabilities import DomainCapabilities +from .logger import log from .osdict import OSDB from .xmlbuilder import XMLBuilder, XMLProperty, XMLChildProperty @@ -91,12 +91,12 @@ class Guest(XMLBuilder): raise RuntimeError(_("Domain named %s already exists!") % name) try: - logging.debug("Explicitly replacing guest '%s'", name) + log.debug("Explicitly replacing guest '%s'", name) if vm.ID() != -1: - logging.debug("Destroying guest '%s'", name) + log.debug("Destroying guest '%s'", name) vm.destroy() - logging.debug("Undefining guest '%s'", name) + log.debug("Undefining guest '%s'", name) vm.undefine() except libvirt.libvirtError as e: raise RuntimeError(_("Could not remove old vm '%s': %s") % @@ -135,7 +135,7 @@ class Guest(XMLBuilder): conn.lookupByUUID, uuid): return uuid - logging.error("Failed to generate non-conflicting UUID") + log.error("Failed to generate non-conflicting UUID") @staticmethod def generate_name(guest): @@ -324,7 +324,7 @@ class Guest(XMLBuilder): if os_id: self.__osinfo = OSDB.lookup_os_by_full_id(os_id) if not self.__osinfo: - logging.debug("XML had libosinfo os id=%s but we didn't " + log.debug("XML had libosinfo os id=%s but we didn't " "find any libosinfo object matching that", os_id) if not self.__osinfo: @@ -459,7 +459,7 @@ class Guest(XMLBuilder): def set_os_name(self, name): obj = OSDB.lookup_os(name, raise_error=True) - logging.debug("Setting Guest osinfo name %s", obj) + log.debug("Setting Guest osinfo name %s", obj) self._set_os_obj(obj) def set_default_os_name(self): @@ -584,7 +584,7 @@ class Guest(XMLBuilder): self.features.smm = True self.os.loader_secure = True if self.os.machine and "q35" not in self.os.machine: - logging.warning("Changing machine type from '%s' to 'q35' " + log.warning("Changing machine type from '%s' to 'q35' " "which is required for UEFI secure boot.") self.os.machine = "q35" @@ -696,7 +696,7 @@ class Guest(XMLBuilder): self.conn.is_qemu() and self.os.is_x86() and self.type != "kvm"): - logging.warning("KVM acceleration not available, using '%s'", + log.warning("KVM acceleration not available, using '%s'", self.type) def sync_vcpus_topology(self): @@ -787,10 +787,10 @@ class Guest(XMLBuilder): except RuntimeError as e: if self.uefi_requested: raise - logging.debug("Error setting UEFI default", + log.debug("Error setting UEFI default", exc_info=True) - logging.warning("Couldn't configure UEFI: %s", e) - logging.warning("Your VM may not boot successfully.") + log.warning("Couldn't configure UEFI: %s", e) + log.warning("Your VM may not boot successfully.") def _usb_disabled(self): controllers = [c for c in self.devices.controller if diff --git a/virtinst/hostkeymap.py b/virtinst/hostkeymap.py index d73d5a65..0609e855 100644 --- a/virtinst/hostkeymap.py +++ b/virtinst/hostkeymap.py @@ -5,10 +5,11 @@ # See the COPYING file in the top-level directory. # -import logging import os import re +from .logger import log + _ETC_VCONSOLE = "/etc/vconsole.conf" _KEYBOARD_DIR = "/etc/sysconfig/keyboard" @@ -105,20 +106,20 @@ def _default_keymap(): kt = cb(f) f.close() if kt: - logging.debug("Found keymap=%s in %s", kt, path) + log.debug("Found keymap=%s in %s", kt, path) break - logging.debug("Didn't find keymap in '%s'", path) + log.debug("Didn't find keymap in '%s'", path) except Exception as e: - logging.debug("Error parsing '%s': %s", path, str(e)) + log.debug("Error parsing '%s': %s", path, str(e)) if kt is None: - logging.debug("Did not parse any usable keymapping.") + log.debug("Did not parse any usable keymapping.") return default kt = kt.lower() keymap = sanitize_keymap(kt) if not keymap: - logging.debug("Didn't match keymap '%s' in keytable!", kt) + log.debug("Didn't match keymap '%s' in keytable!", kt) return default return keymap diff --git a/virtinst/installer.py b/virtinst/installer.py index c43b4818..f86af334 100644 --- a/virtinst/installer.py +++ b/virtinst/installer.py @@ -7,7 +7,7 @@ # See the COPYING file in the top-level directory. import os -import logging +from .logger import log from . import progress from . import unattended @@ -210,7 +210,7 @@ class Installer(object): ram = guest.osinfo.get_network_install_required_ram(guest) ram = (ram or 0) // 1024 if ram > guest.currentMemory: - logging.warning(_("Overriding memory to %s MiB needed for %s " + log.warning(_("Overriding memory to %s MiB needed for %s " "network install."), ram // 1024, guest.osinfo.name) guest.currentMemory = ram @@ -222,7 +222,7 @@ class Installer(object): def _prepare_unattended_data(self, guest, script): expected_filename = script.get_expected_filename() unattended_cmdline = script.generate_cmdline() - logging.debug("Generated unattended cmdline: %s", unattended_cmdline) + log.debug("Generated unattended cmdline: %s", unattended_cmdline) scriptpath = script.write() self._tmpfiles.append(scriptpath) @@ -244,7 +244,7 @@ class Installer(object): raise RuntimeError("Unattended method=cdrom installs are " "not yet supported for remote connections.") if not guest.osinfo.is_windows(): - logging.warning("Attempting unattended method=cdrom injection " + log.warning("Attempting unattended method=cdrom injection " "for a non-windows OS. If this doesn't work, try " "passing install media to --location") osguess = OSDB.guess_os_by_iso(self.cdrom) @@ -271,7 +271,7 @@ class Installer(object): self._treemedia.cleanup(guest) for f in self._tmpfiles: - logging.debug("Removing %s", str(f)) + log.debug("Removing %s", str(f)) os.unlink(f) def _get_postinstall_bootdev(self, guest): @@ -386,16 +386,16 @@ class Installer(object): ret = self._treemedia.detect_distro(guest) elif self.cdrom: if guest.conn.is_remote(): - logging.debug("Can't detect distro for cdrom " + log.debug("Can't detect distro for cdrom " "remote connection.") else: osguess = OSDB.guess_os_by_iso(self.cdrom) if osguess: ret = osguess[0] else: - logging.debug("No media for distro detection.") + log.debug("No media for distro detection.") - logging.debug("installer.detect_distro returned=%s", ret) + log.debug("installer.detect_distro returned=%s", ret) return ret def set_unattended_data(self, unattended_data): @@ -438,9 +438,9 @@ class Installer(object): install_xml = self._get_install_xml(guest, meter) final_xml = guest.get_xml() - logging.debug("Generated install XML: %s", + log.debug("Generated install XML: %s", (install_xml and ("\n" + install_xml) or "None required")) - logging.debug("Generated boot XML: \n%s", final_xml) + log.debug("Generated boot XML: \n%s", final_xml) return install_xml, final_xml @@ -493,10 +493,10 @@ class Installer(object): domain = self.conn.defineXML(final_xml) try: - logging.debug("XML fetched from libvirt object:\n%s", + log.debug("XML fetched from libvirt object:\n%s", domain.XMLDesc(0)) except Exception as e: # pragma: no cover - logging.debug("Error fetching XML from libvirt object: %s", e) + log.debug("Error fetching XML from libvirt object: %s", e) return domain def _flag_autostart(self, domain): @@ -508,7 +508,7 @@ class Installer(object): except Exception as e: # pragma: no cover if not self.conn.support.is_error_nosupport(e): raise - logging.warning("Could not set autostart flag: libvirt " + log.warning("Could not set autostart flag: libvirt " "connection does not support autostart.") @@ -562,7 +562,7 @@ class Installer(object): return for disk in clean_disks: - logging.debug("Removing created disk path=%s vol_object=%s", + log.debug("Removing created disk path=%s vol_object=%s", disk.path, disk.get_vol_object()) name = os.path.basename(disk.path) @@ -578,6 +578,6 @@ class Installer(object): meter.end(0) except Exception as e: # pragma: no cover - logging.debug("Failed to remove disk '%s'", + log.debug("Failed to remove disk '%s'", name, exc_info=True) - logging.error("Failed to remove disk '%s': %s", name, e) + log.error("Failed to remove disk '%s': %s", name, e) diff --git a/virtinst/installerinject.py b/virtinst/installerinject.py index 8619b718..b38fe963 100644 --- a/virtinst/installerinject.py +++ b/virtinst/installerinject.py @@ -4,15 +4,16 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os import shutil import subprocess import tempfile +from .logger import log + def _run_initrd_commands(initrd, tempdir): - logging.debug("Appending to the initrd.") + log.debug("Appending to the initrd.") find_proc = subprocess.Popen(['find', '.', '-print0'], stdout=subprocess.PIPE, @@ -36,11 +37,11 @@ def _run_initrd_commands(initrd, tempdir): cpioerr = cpio_proc.stderr.read() gziperr = gzip_proc.stderr.read() if finderr: # pragma: no cover - logging.debug("find stderr=%s", finderr) + log.debug("find stderr=%s", finderr) if cpioerr: # pragma: no cover - logging.debug("cpio stderr=%s", cpioerr) + log.debug("cpio stderr=%s", cpioerr) if gziperr: # pragma: no cover - logging.debug("gzip stderr=%s", gziperr) + log.debug("gzip stderr=%s", gziperr) def _run_iso_commands(iso, tempdir): @@ -50,9 +51,9 @@ def _run_iso_commands(iso, tempdir): "-input-charset", "utf8", "-rational-rock", tempdir] - logging.debug("Running iso build command: %s", cmd) + log.debug("Running iso build command: %s", cmd) output = subprocess.check_output(cmd, stderr=subprocess.STDOUT) - logging.debug("cmd output: %s", output) + log.debug("cmd output: %s", output) def _perform_generic_injections(injections, scratchdir, media, cb): @@ -69,7 +70,7 @@ def _perform_generic_injections(injections, scratchdir, media, cb): else: dst = os.path.basename(filename) - logging.debug("Injecting src=%s dst=%s into media=%s", + log.debug("Injecting src=%s dst=%s into media=%s", filename, dst, media) shutil.copy(filename, os.path.join(tempdir, dst)) diff --git a/virtinst/installertreemedia.py b/virtinst/installertreemedia.py index 951fd911..7c9d8e93 100644 --- a/virtinst/installertreemedia.py +++ b/virtinst/installertreemedia.py @@ -4,7 +4,6 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os from . import progress @@ -13,6 +12,7 @@ from . import urlfetcher from .devices import DeviceDisk from .installerinject import perform_initrd_injections from .kernelupload import upload_kernel_initrd +from .logger import log from .osdict import OSDB @@ -59,9 +59,9 @@ class InstallerTreeMedia(object): dev.validate() return dev.path except Exception as e: - logging.debug("Error validating install location", exc_info=True) + log.debug("Error validating install location", exc_info=True) if path.startswith("nfs:"): - logging.warning("NFS URL installs are no longer supported. " + log.warning("NFS URL installs are no longer supported. " "Access your install media over an alternate transport " "like HTTP, or manually mount the NFS share and install " "from the local directory mount point.") @@ -240,7 +240,7 @@ class InstallerTreeMedia(object): install_args = None if unattended_script: install_args = unattended_script.generate_cmdline() - logging.debug("Generated unattended cmdline: %s", install_args) + log.debug("Generated unattended cmdline: %s", install_args) elif self.is_network_url() and cache.kernel_url_arg: install_args = "%s=%s" % (cache.kernel_url_arg, self.location) @@ -264,11 +264,11 @@ class InstallerTreeMedia(object): def cleanup(self, guest): ignore = guest for f in self._tmpfiles: - logging.debug("Removing %s", str(f)) + log.debug("Removing %s", str(f)) os.unlink(f) for vol in self._tmpvols: - logging.debug("Removing volume '%s'", vol.name()) + log.debug("Removing volume '%s'", vol.name()) vol.delete(0) self._tmpvols = [] diff --git a/virtinst/kernelupload.py b/virtinst/kernelupload.py index 9ebfe2f9..e4e2a83a 100644 --- a/virtinst/kernelupload.py +++ b/virtinst/kernelupload.py @@ -4,10 +4,10 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os from . import progress +from .logger import log from .devices import DeviceDisk from .storage import StoragePool, StorageVolume @@ -19,12 +19,12 @@ def _build_pool(conn, meter, path): """ pool = StoragePool.lookup_pool_by_path(conn, path) if pool: # pragma: no cover - logging.debug("Existing pool '%s' found for %s", pool.name(), path) + log.debug("Existing pool '%s' found for %s", pool.name(), path) StoragePool.ensure_pool_is_running(pool, refresh=True) return pool name = StoragePool.find_free_name(conn, "boot-scratch") - logging.debug("Building storage pool: path=%s name=%s", path, name) + log.debug("Building storage pool: path=%s name=%s", path, name) poolbuild = StoragePool(conn) poolbuild.type = poolbuild.TYPE_DIR poolbuild.name = name @@ -77,7 +77,7 @@ def _upload_file(conn, meter, destpool, src): size = os.path.getsize(src) basename = os.path.basename(src) name = StorageVolume.find_free_name(conn, destpool, basename) - logging.debug("Generated volume name %s", name) + log.debug("Generated volume name %s", name) vol_install = DeviceDisk.build_vol_install(conn, name, destpool, (float(size) / 1024.0 / 1024.0 / 1024.0), True) @@ -138,17 +138,17 @@ def upload_kernel_initrd(conn, scratchdir, system_scratchdir, if (not conn.is_remote() and (conn.is_session_uri() or scratchdir == system_scratchdir)): # We have access to system scratchdir, don't jump through hoops - logging.debug("Have access to preferred scratchdir so" + log.debug("Have access to preferred scratchdir so" " nothing to upload") # pragma: no cover return kernel, initrd, tmpvols # pragma: no cover if not conn.support_remote_url_install(): # Needed for the test_urls suite - logging.debug("Media upload not supported") # pragma: no cover + log.debug("Media upload not supported") # pragma: no cover return kernel, initrd, tmpvols # pragma: no cover # Build pool - logging.debug("Uploading kernel/initrd media") + log.debug("Uploading kernel/initrd media") pool = _build_pool(conn, meter, system_scratchdir) kvol = _upload_file(conn, meter, pool, kernel) diff --git a/virtinst/logger.py b/virtinst/logger.py new file mode 100644 index 00000000..07244c0d --- /dev/null +++ b/virtinst/logger.py @@ -0,0 +1,9 @@ +# Copyright 2019 Red Hat, Inc. +# +# This work is licensed under the GNU GPLv2 or later. +# See the COPYING file in the top-level directory. + +import logging + +# This is exported by virtinst/__init__.py +log = logging.getLogger("virtinst") diff --git a/virtinst/nodedev.py b/virtinst/nodedev.py index ce62ddb0..9d2c8f10 100644 --- a/virtinst/nodedev.py +++ b/virtinst/nodedev.py @@ -4,9 +4,9 @@ # This work is licensed under the GNU GPLv2 or later. # See the COPYING file in the top-level directory. -import logging import os +from .logger import log from .xmlbuilder import XMLBuilder, XMLProperty, XMLChildProperty @@ -66,7 +66,7 @@ class NodeDevice(XMLBuilder): try: return _AddressStringToNodedev(conn, idstring) except Exception: - logging.debug("Error looking up nodedev from idstring=%s", + log.debug("Error looking up nodedev from idstring=%s", idstring, exc_info=True) raise @@ -206,7 +206,7 @@ def _AddressStringToHostdev(conn, addrstr): else: raise RuntimeError("Unknown address type") except Exception: - logging.debug("Error parsing node device string.", exc_info=True) + log.debug("Error parsing node device string.", exc_info=True) raise return hostdev diff --git a/virtinst/osdict.py b/virtinst/osdict.py index c24a0445..467242c0 100644 --- a/virtinst/osdict.py +++ b/virtinst/osdict.py @@ -7,12 +7,13 @@ # See the COPYING file in the top-level directory. import datetime -import logging import os import re from gi.repository import Libosinfo +from .logger import log + def _in_testsuite(): return "VIRTINST_TEST_SUITE" in os.environ @@ -221,7 +222,7 @@ class _OSDB(object): if key in self._aliases: alias = self._aliases[key] # Added 2018-10-02. Maybe remove aliases in a year - logging.warning( + log.warning( _("OS name '%s' is deprecated, using '%s' instead. " "This alias will be removed in the future."), key, alias) key = alias @@ -236,7 +237,7 @@ class _OSDB(object): try: media = Libosinfo.Media.create_from_location(location, None) except Exception as e: - logging.debug("Error creating libosinfo media object: %s", str(e)) + log.debug("Error creating libosinfo media object: %s", str(e)) return None if not self._os_loader.get_db().identify_media(media): @@ -255,7 +256,7 @@ class _OSDB(object): try: tree = Libosinfo.Tree.create_from_location(location, None) except Exception as e: - logging.debug("Error creating libosinfo tree object for " + log.debug("Error creating libosinfo tree object for " "location=%s : %s", location, str(e)) return None @@ -321,7 +322,7 @@ class _OsResources: # value as an approximation at a 'recommended' value val = self._get_minimum_key(key, arch) if val: - logging.debug("No recommended value found for key='%s', " + log.debug("No recommended value found for key='%s', " "using minimum=%s * 2", key, val) return val * 2 return None diff --git a/virtinst/pollhelpers.py b/virtinst/pollhelpers.py index 8db2ebb6..20edc522 100644 --- a/virtinst/pollhelpers.py +++ b/virtinst/pollhelpers.py @@ -5,7 +5,7 @@ # See the COPYING file in the top-level directory. # -import logging +from .logger import log # Debugging helper to force old style polling @@ -24,7 +24,7 @@ def _new_poll_helper(origmap, typename, listfunc, buildfunc): try: objs = listfunc() except Exception as e: - logging.debug("Unable to list all %ss: %s", typename, e) + log.debug("Unable to list all %ss: %s", typename, e) for obj in objs: connkey = obj.name() @@ -64,11 +64,11 @@ def _old_poll_helper(origmap, typename, try: newActiveNames = active_list() except Exception as e: - logging.debug("Unable to list active %ss: %s", typename, e) + log.debug("Unable to list active %ss: %s", typename, e) try: newInactiveNames = inactive_list() except Exception as e: - logging.debug("Unable to list inactive %ss: %s", typename, e) + log.debug("Unable to list inactive %ss: %s", typename, e) def check_obj(name): obj = None @@ -78,7 +78,7 @@ def _old_poll_helper(origmap, typename, try: obj = lookup_func(name) except Exception as e: - logging.debug("Could not fetch %s '%s': %s", + log.debug("Could not fetch %s '%s': %s", typename, connkey, e) return @@ -94,7 +94,7 @@ def _old_poll_helper(origmap, typename, try: check_obj(name) except Exception: - logging.exception("Couldn't fetch %s '%s'", typename, name) + log.exception("Couldn't fetch %s '%s'", typename, name) return (list(origmap.values()), list(new.values()), list(current.values())) @@ -201,12 +201,12 @@ def _old_fetch_vms(backend, origmap, build_func): try: newActiveIDs = backend.listDomainsID() except Exception as e: - logging.debug("Unable to list active domains: %s", e) + log.debug("Unable to list active domains: %s", e) try: newInactiveNames = backend.listDefinedDomains() except Exception as e: - logging.exception("Unable to list inactive domains: %s", e) + log.exception("Unable to list inactive domains: %s", e) def add_vm(vm): connkey = vm.get_name() @@ -237,7 +237,7 @@ def _old_fetch_vms(backend, origmap, build_func): check_new(vm, connkey) except Exception: - logging.exception("Couldn't fetch domain id '%s'", _id) + log.exception("Couldn't fetch domain id '%s'", _id) for name in newInactiveNames: @@ -253,7 +253,7 @@ def _old_fetch_vms(backend, origmap, build_func): check_new(vm, connkey) except Exception: - logging.exception("Couldn't fetch domain '%s'", name) + log.exception("Couldn't fetch domain '%s'", name) return (list(origmap.values()), list(new.values()), list(current.values())) diff --git a/virtinst/storage.py b/virtinst/storage.py index d3741e36..eee92106 100644 --- a/virtinst/storage.py +++ b/virtinst/storage.py @@ -5,13 +5,13 @@ # See the COPYING file in the top-level directory. import os -import logging import threading import libvirt from . import generatename from . import progress +from .logger import log from .xmlbuilder import XMLBuilder, XMLChildProperty, XMLProperty @@ -82,7 +82,7 @@ def _lookup_default_pool(conn): poolxml = _lookup_poolxml_by_path(conn, path) if poolxml: - logging.debug("Found default pool name=%s target=%s", + log.debug("Found default pool name=%s target=%s", poolxml.name, poolxml.target_path) return poolxml @@ -210,7 +210,7 @@ class StoragePool(_StorageObject): try: name = "default" path = _preferred_default_pool_path(conn) - logging.debug("Attempting to build default pool with target '%s'", + log.debug("Attempting to build default pool with target '%s'", path) defpool = StoragePool(conn) defpool.type = defpool.TYPE_DIR @@ -259,10 +259,10 @@ class StoragePool(_StorageObject): :param refresh: If True, run refresh() as well """ if pool_object.info()[0] != libvirt.VIR_STORAGE_POOL_RUNNING: - logging.debug("starting pool=%s", pool_object.name()) + log.debug("starting pool=%s", pool_object.name()) pool_object.create(0) if refresh: - logging.debug("refreshing pool=%s", pool_object.name()) + log.debug("refreshing pool=%s", pool_object.name()) pool_object.refresh(0) @@ -476,7 +476,7 @@ class StoragePool(_StorageObject): "formatting disk device.")) xml = self.get_xml() - logging.debug("Creating storage pool '%s' with xml:\n%s", + log.debug("Creating storage pool '%s' with xml:\n%s", self.name, xml) meter = progress.ensure_meter(meter) @@ -510,7 +510,7 @@ class StoragePool(_StorageObject): try: pool.undefine() except Exception as e: - logging.debug("Error cleaning up pool after failure: %s", + log.debug("Error cleaning up pool after failure: %s", str(e)) raise RuntimeError(errmsg) @@ -677,27 +677,27 @@ class StorageVolume(_StorageObject): def _detect_backing_store_format(self): - logging.debug("Attempting to detect format for backing_store=%s", + log.debug("Attempting to detect format for backing_store=%s", self.backing_store) from . import diskbackend vol, pool = diskbackend.manage_path(self.conn, self.backing_store) if not vol: - logging.debug("Didn't find any volume for backing_store") + log.debug("Didn't find any volume for backing_store") return None # Only set backing format for volumes that support # the 'format' parameter as we know it, like qcow2 etc. volxml = StorageVolume(self.conn, vol.XMLDesc(0)) volxml.pool = pool - logging.debug("Found backing store volume XML:\n%s", + log.debug("Found backing store volume XML:\n%s", volxml.get_xml()) if volxml.supports_property("format"): - logging.debug("Returning format=%s", volxml.format) + log.debug("Returning format=%s", volxml.format) return volxml.format - logging.debug("backing_store volume doesn't appear to have " + log.debug("backing_store volume doesn't appear to have " "a file format we can specify, returning None") return None @@ -733,7 +733,7 @@ class StorageVolume(_StorageObject): if self._pool_xml.type == StoragePool.TYPE_LOGICAL: if self.allocation != self.capacity: - logging.warning(_("Sparse logical volumes are not supported, " + log.warning(_("Sparse logical volumes are not supported, " "setting allocation equal to capacity")) self.allocation = self.capacity @@ -741,7 +741,7 @@ class StorageVolume(_StorageObject): if isfatal: raise ValueError(errmsg) if errmsg: - logging.warning(errmsg) + log.warning(errmsg) def install(self, meter=None): """ @@ -751,7 +751,7 @@ class StorageVolume(_StorageObject): self.backing_format = self._detect_backing_store_format() xml = self.get_xml() - logging.debug("Creating storage volume '%s' with xml:\n%s", + log.debug("Creating storage volume '%s' with xml:\n%s", self.name, xml) t = threading.Thread(target=self._progress_thread, @@ -786,17 +786,17 @@ class StorageVolume(_StorageObject): if self.input_vol: vol = self.pool.createXMLFrom(xml, self.input_vol, cloneflags) else: - logging.debug("Using vol create flags=%s", createflags) + log.debug("Using vol create flags=%s", createflags) vol = self.pool.createXML(xml, createflags) self._install_finished.set() t.join() meter.end(self.capacity) - logging.debug("Storage volume '%s' install complete.", + log.debug("Storage volume '%s' install complete.", self.name) return vol except Exception as e: - logging.debug("Error creating storage volume", exc_info=True) + log.debug("Error creating storage volume", exc_info=True) raise RuntimeError("Couldn't create storage volume " "'%s': '%s'" % (self.name, str(e))) @@ -816,7 +816,7 @@ class StorageVolume(_StorageObject): break if vol is None: - logging.debug("Couldn't lookup storage volume in prog thread.") + log.debug("Couldn't lookup storage volume in prog thread.") return while True: diff --git a/virtinst/unattended.py b/virtinst/unattended.py index 9c7a5c53..a0b6fc27 100644 --- a/virtinst/unattended.py +++ b/virtinst/unattended.py @@ -8,13 +8,14 @@ import getpass import locale -import logging import os import pwd import tempfile from gi.repository import Libosinfo +from .logger import log + def _make_installconfig(script, osobj, unattended_data, arch, hostname, url): """ @@ -95,20 +96,20 @@ def _make_installconfig(script, osobj, unattended_data, arch, hostname, url): if unattended_data.product_key: config.set_reg_product_key(unattended_data.product_key) - logging.debug("InstallScriptConfig created with the following params:") - logging.debug("username: %s", config.get_user_login()) - logging.debug("realname: %s", config.get_user_realname()) - logging.debug("user password: %s", config.get_user_password()) - logging.debug("admin password: %s", config.get_admin_password()) - logging.debug("target disk: %s", config.get_target_disk()) - logging.debug("hardware arch: %s", config.get_hardware_arch()) - logging.debug("hostname: %s", config.get_hostname()) - logging.debug("timezone: %s", config.get_l10n_timezone()) - logging.debug("language: %s", config.get_l10n_language()) - logging.debug("keyboard: %s", config.get_l10n_keyboard()) - logging.debug("url: %s", + log.debug("InstallScriptConfig created with the following params:") + log.debug("username: %s", config.get_user_login()) + log.debug("realname: %s", config.get_user_realname()) + log.debug("user password: %s", config.get_user_password()) + log.debug("admin password: %s", config.get_admin_password()) + log.debug("target disk: %s", config.get_target_disk()) + log.debug("hardware arch: %s", config.get_hardware_arch()) + log.debug("hostname: %s", config.get_hostname()) + log.debug("timezone: %s", config.get_l10n_timezone()) + log.debug("language: %s", config.get_l10n_language()) + log.debug("keyboard: %s", config.get_l10n_keyboard()) + log.debug("url: %s", config.get_installation_url()) # pylint: disable=no-member - logging.debug("product-key: %s", config.get_reg_product_key()) + log.debug("product-key: %s", config.get_reg_product_key()) return config @@ -147,7 +148,7 @@ class OSInstallScript: "initrd": Libosinfo.InstallScriptInjectionMethod.INITRD, } - logging.debug("Using '%s' injection method", namestr) + log.debug("Using '%s' injection method", namestr) injection_method = names[namestr] supported_injection_methods = self._script.get_injection_methods() if (injection_method & supported_injection_methods == 0): @@ -164,7 +165,7 @@ class OSInstallScript: "network": Libosinfo.InstallScriptInstallationSource.NETWORK, } - logging.debug("Using '%s' installation source", namestr) + log.debug("Using '%s' installation source", namestr) self._script.set_installation_source(names[namestr]) def _requires_param(self, config_param): @@ -196,8 +197,8 @@ class OSInstallScript: content = self.generate() open(scriptpath, "w").write(content) - logging.debug("Generated unattended script: %s", scriptpath) - logging.debug("Generated script contents:\n%s", content) + log.debug("Generated unattended script: %s", scriptpath) + log.debug("Generated script contents:\n%s", content) return scriptpath @@ -265,7 +266,7 @@ def _lookup_rawscript(osinfo, profile, os_media): (osinfo.name, profile, ", ".join(profile_names))) else: profile = _find_default_profile(profile_names) - logging.warning(_("Using unattended profile '%s'"), profile) + log.warning(_("Using unattended profile '%s'"), profile) rawscripts = script_map[profile] # Some OSes (as Windows) have more than one installer script, @@ -273,7 +274,7 @@ def _lookup_rawscript(osinfo, profile, os_media): # perform the unattended installation. Let's just deal with # multiple installer scripts when its actually needed, though. usescript = rawscripts[0] - logging.debug("Install script found for profile '%s': %s", + log.debug("Install script found for profile '%s': %s", profile, usescript.get_id()) return usescript diff --git a/virtinst/uri.py b/virtinst/uri.py index bb0ef037..cc1fb96b 100644 --- a/virtinst/uri.py +++ b/virtinst/uri.py @@ -5,10 +5,11 @@ # See the COPYING file in the top-level directory. # -import logging import re import urllib.parse +from .logger import log + def sanitize_xml_for_test_define(xml): import difflib @@ -23,7 +24,7 @@ def sanitize_xml_for_test_define(xml): diff = "\n".join(difflib.unified_diff(orig.split("\n"), xml.split("\n"))) if diff: - logging.debug("virtinst test sanitizing diff\n:%s", diff) + log.debug("virtinst test sanitizing diff\n:%s", diff) return xml diff --git a/virtinst/urldetect.py b/virtinst/urldetect.py index f640f790..cc5062a0 100644 --- a/virtinst/urldetect.py +++ b/virtinst/urldetect.py @@ -5,9 +5,9 @@ # See the COPYING file in the top-level directory. import configparser -import logging import re +from .logger import log from .osdict import OSDB @@ -39,7 +39,7 @@ class _DistroCache(object): content = self._fetcher.acquireFileContent(path) except ValueError: content = None - logging.debug("Failed to acquire file=%s", path) + log.debug("Failed to acquire file=%s", path) self._filecache[path] = content return self._filecache[path] @@ -68,15 +68,15 @@ class _DistroCache(object): treeinfo.read_string(treeinfostr) self.treeinfo_family = treeinfo.get("general", "family") self._treeinfo = treeinfo - logging.debug("treeinfo family=%s", self.treeinfo_family) + log.debug("treeinfo family=%s", self.treeinfo_family) if self._treeinfo.has_option("general", "version"): self.treeinfo_version = self._treeinfo.get("general", "version") - logging.debug("Found treeinfo version=%s", self.treeinfo_version) + log.debug("Found treeinfo version=%s", self.treeinfo_version) if self._treeinfo.has_option("general", "name"): self.treeinfo_name = self._treeinfo.get("general", "name") - logging.debug("Found treeinfo name=%s", self.treeinfo_name) + log.debug("Found treeinfo name=%s", self.treeinfo_name) return self._treeinfo @@ -87,7 +87,7 @@ class _DistroCache(object): ret = bool(re.match(famregex, self.treeinfo_family)) self.treeinfo_matched = ret if not ret: - logging.debug("Didn't match treeinfo family regex=%s", famregex) + log.debug("Didn't match treeinfo family regex=%s", famregex) return ret def content_regex(self, filename, regex): @@ -102,7 +102,7 @@ class _DistroCache(object): if re.match(regex, line): return True - logging.debug("found filename=%s but regex=%s didn't match", + log.debug("found filename=%s but regex=%s didn't match", filename, regex) return False @@ -121,7 +121,7 @@ class _DistroCache(object): return [(_get_treeinfo_path("kernel"), _get_treeinfo_path("initrd"))] except Exception: # pragma: no cover - logging.debug("Failed to parse treeinfo kernel/initrd", + log.debug("Failed to parse treeinfo kernel/initrd", exc_info=True) return [] @@ -141,7 +141,7 @@ class _DistroCache(object): version = _safeint(verstr.split(".")[0]) update = _safeint(verstr.split(".")[1]) - logging.debug("converted verstr=%s to version=%s update=%s", + log.debug("converted verstr=%s to version=%s update=%s", verstr, version, update) return version, update @@ -158,7 +158,7 @@ class _DistroCache(object): not self.libosinfo_mediaobj.get_initrd_path()): # This can happen if the media is live media, or just # with incomplete libosinfo data - logging.debug("libosinfo didn't report any media kernel/initrd " + log.debug("libosinfo didn't report any media kernel/initrd " "path for detected os_variant=%s", self.libosinfo_mediaobj) return False @@ -187,12 +187,12 @@ class _SUSEContent(object): if line.startswith(prefix + " "): self.content_dict[prefix] = line.split(" ", 1)[1] - logging.debug("SUSE content dict: %s", str(self.content_dict)) + log.debug("SUSE content dict: %s", str(self.content_dict)) self.tree_arch = self._get_tree_arch() self.product_name = self._get_product_name() self.product_version = self._get_product_version() - logging.debug("SUSE content product_name=%s product_version=%s " + log.debug("SUSE content product_name=%s product_version=%s " "tree_arch=%s", self.product_name, self.product_version, self.tree_arch) @@ -238,7 +238,7 @@ class _SUSEContent(object): elif "," in self.content_dict.get("DISTRO", ""): product_name = self.content_dict["DISTRO"].rsplit(",", 1)[1] - logging.debug("SUSE content product_name=%s", product_name) + log.debug("SUSE content product_name=%s", product_name) return product_name def _get_product_version(self): @@ -278,7 +278,7 @@ class _SUSEContent(object): def getDistroStore(guest, fetcher, skip_error): - logging.debug("Finding distro store for location=%s", fetcher.location) + log.debug("Finding distro store for location=%s", fetcher.location) arch = guest.os.arch _type = guest.os.os_type @@ -291,7 +291,7 @@ def getDistroStore(guest, fetcher, skip_error): continue store = sclass(fetcher.location, arch, _type, cache) - logging.debug("Detected class=%s osvariant=%s", + log.debug("Detected class=%s osvariant=%s", store.__class__.__name__, store.get_osdict_info()) return store @@ -338,7 +338,7 @@ class _DistroTree(object): self._os_variant = self._detect_version() if self._os_variant and not OSDB.lookup_os(self._os_variant): - logging.debug("Detected os_variant as %s, which is not " + log.debug("Detected os_variant as %s, which is not " "in osdict.", self._os_variant) self._os_variant = None @@ -361,7 +361,7 @@ class _DistroTree(object): """ Hook for subclasses to detect media os variant. """ - logging.debug("%s does not implement any osdict detection", self) + log.debug("%s does not implement any osdict detection", self) return None @@ -403,13 +403,13 @@ class _FedoraDistro(_DistroTree): verstr = self.cache.treeinfo_version if not verstr: # pragma: no cover - logging.debug("No treeinfo version? Assume latest_variant=%s", + log.debug("No treeinfo version? Assume latest_variant=%s", latest_variant) return latest_variant # rawhide trees changed to use version=Rawhide in Apr 2016 if verstr in ["development", "rawhide", "Rawhide"]: - logging.debug("treeinfo version=%s, using latest_variant=%s", + log.debug("treeinfo version=%s, using latest_variant=%s", verstr, latest_variant) return latest_variant @@ -418,7 +418,7 @@ class _FedoraDistro(_DistroTree): if OSDB.lookup_os(variant): return variant - logging.debug( # pragma: no cover + log.debug( # pragma: no cover "variant=%s from treeinfo version=%s not found, " "using latest_variant=%s", variant, verstr, latest_variant) return latest_variant # pragma: no cover @@ -439,7 +439,7 @@ class _RHELDistro(_DistroTree): def _detect_version(self): if not self.cache.treeinfo_version: - logging.debug("No treeinfo version? Not setting an os_variant") + log.debug("No treeinfo version? Not setting an os_variant") return version, update = self.cache.split_version() @@ -488,7 +488,7 @@ class _SuseDistro(_RHELDistro): try: cache.suse_content = _SUSEContent(content_str) except Exception as e: - logging.debug("Error parsing SUSE content file: %s", str(e)) + log.debug("Error parsing SUSE content file: %s", str(e)) return False if not cache.suse_content: @@ -674,7 +674,7 @@ class _DebianDistro(_DistroTree): arch = re.findall(pattern, self.uri) if not arch: continue - logging.debug("Found pattern=%s treearch=%s in uri", + log.debug("Found pattern=%s treearch=%s in uri", pattern, arch[0]) return arch[0] @@ -682,14 +682,14 @@ class _DebianDistro(_DistroTree): # in the URI name for --location $ISO mounts for arch in ["i386", "amd64", "x86_64", "arm64"]: if arch in self.uri: - logging.debug("Found treearch=%s in uri", arch) + log.debug("Found treearch=%s in uri", arch) if arch == "x86_64": arch = "amd64" return arch # Otherwise default to i386 arch = "i386" - logging.debug("No treearch found in uri, defaulting to arch=%s", arch) + log.debug("No treearch found in uri, defaulting to arch=%s", arch) return arch def _set_url_paths(self): @@ -745,7 +745,7 @@ class _DebianDistro(_DistroTree): oses = [n for n in OSDB.list_os() if n.name.startswith(self._debname)] if self.cache.debian_media_type == "daily": - logging.debug("Appears to be debian 'daily' URL, using latest " + log.debug("Appears to be debian 'daily' URL, using latest " "debian OS") return oses[0].name @@ -760,7 +760,7 @@ class _DebianDistro(_DistroTree): codename = osobj.label.split()[1].lower() if ("/%s/" % codename) in self.uri: - logging.debug("Found codename=%s in the URL string", codename) + log.debug("Found codename=%s in the URL string", codename) return osobj.name @@ -841,7 +841,7 @@ def _build_distro_list(osobj): # If user manually specified an os_distro, bump its URL class # to the top of the list if osobj.distro: - logging.debug("variant=%s has distro=%s, looking for matching " + log.debug("variant=%s has distro=%s, looking for matching " "distro store to prioritize", osobj.name, osobj.distro) found_store = None @@ -850,11 +850,11 @@ def _build_distro_list(osobj): found_store = store if found_store: - logging.debug("Prioritizing distro store=%s", found_store) + log.debug("Prioritizing distro store=%s", found_store) allstores.remove(found_store) allstores.insert(0, found_store) else: - logging.debug("No matching store found, not prioritizing anything") + log.debug("No matching store found, not prioritizing anything") import os force_libosinfo = os.environ.get("VIRTINST_TEST_SUITE_FORCE_LIBOSINFO") diff --git a/virtinst/urlfetcher.py b/virtinst/urlfetcher.py index fdfdabe3..1ccaf93b 100644 --- a/virtinst/urlfetcher.py +++ b/virtinst/urlfetcher.py @@ -8,7 +8,6 @@ import ftplib import io -import logging import os import subprocess import tempfile @@ -16,6 +15,8 @@ import urllib import requests +from .logger import log + ############################## # Mocking for the test suite # @@ -43,7 +44,7 @@ def _make_mock_url(url, filesyntax): class _MockRequestsResponse: def __init__(self, url): - logging.debug("mocking requests session for url=%s", url) + log.debug("mocking requests session for url=%s", url) fn = _make_mock_url(url, filesyntax=False) self._content = open(fn).read() self.headers = {'content-length': len(self._content)} @@ -100,7 +101,7 @@ class _URLFetcher(object): self.scratchdir = scratchdir self.meter = meter - logging.debug("Using scratchdir=%s", scratchdir) + log.debug("Using scratchdir=%s", scratchdir) self._prepare() @@ -135,7 +136,7 @@ class _URLFetcher(object): raise ValueError(_("Couldn't acquire file %s: %s") % (url, str(e))) - logging.debug("Fetching URI: %s", url) + log.debug("Fetching URI: %s", url) self.meter.start( text=_("Retrieving file %s...") % os.path.basename(filename), size=size) @@ -203,7 +204,7 @@ class _URLFetcher(object): """ url = self._make_full_url(filename) ret = self._hasFile(url) - logging.debug("hasFile(%s) returning %s", url, ret) + log.debug("hasFile(%s) returning %s", url, ret) return ret def acquireFile(self, filename, fullurl=None): @@ -220,7 +221,7 @@ class _URLFetcher(object): fn = fileobj.name self._grabURL(filename, fileobj, fullurl=fullurl) - logging.debug("Saved file to %s", fn) + log.debug("Saved file to %s", fn) return fn except: # noqa if fn and os.path.exists(fn): # pragma: no cover @@ -250,7 +251,7 @@ class _HTTPURLFetcher(_URLFetcher): try: self._session.close() except Exception: # pragma: no cover - logging.debug("Error closing requests.session", exc_info=True) + log.debug("Error closing requests.session", exc_info=True) self._session = None def can_access(self): @@ -264,7 +265,7 @@ class _HTTPURLFetcher(_URLFetcher): response = self._session.head(url, allow_redirects=True) response.raise_for_status() except Exception as e: # pragma: no cover - logging.debug("HTTP hasFile request failed: %s", str(e)) + log.debug("HTTP hasFile request failed: %s", str(e)) return False return True @@ -335,7 +336,7 @@ class _FTPURLFetcher(_URLFetcher): try: self._ftp.quit() except Exception: # pragma: no cover - logging.debug("Error quitting ftp connection", exc_info=True) + log.debug("Error quitting ftp connection", exc_info=True) self._ftp = None @@ -350,7 +351,7 @@ class _FTPURLFetcher(_URLFetcher): # If it's a dir self._ftp.cwd(path) except ftplib.all_errors as e: # pragma: no cover - logging.debug("FTP hasFile: couldn't access %s: %s", + log.debug("FTP hasFile: couldn't access %s: %s", url, str(e)) return False @@ -383,7 +384,7 @@ class _ISOURLFetcher(_URLFetcher): cmd = ["isoinfo", "-J", "-i", self.location, "-x", url] - logging.debug("Running isoinfo: %s", cmd) + log.debug("Running isoinfo: %s", cmd) output = subprocess.check_output(cmd) return io.BytesIO(output), len(output) @@ -395,7 +396,7 @@ class _ISOURLFetcher(_URLFetcher): if not self._cache_file_list: cmd = ["isoinfo", "-J", "-i", self.location, "-f"] - logging.debug("Running isoinfo: %s", cmd) + log.debug("Running isoinfo: %s", cmd) output = subprocess.check_output(cmd, stderr=subprocess.DEVNULL) self._cache_file_list = output.splitlines(False) diff --git a/virtinst/xmlbuilder.py b/virtinst/xmlbuilder.py index bb34b17b..ec4f0a5c 100644 --- a/virtinst/xmlbuilder.py +++ b/virtinst/xmlbuilder.py @@ -7,12 +7,12 @@ # See the COPYING file in the top-level directory. import collections -import logging import os import re import string import textwrap +from .logger import log from .xmlapi import XMLAPI from . import xmlutil @@ -233,7 +233,7 @@ class XMLProperty(_XMLPropertyBase): intkwargs["base"] = 16 ret = int(val, **intkwargs) except ValueError as e: - logging.debug("Error converting XML value to int: %s", e) + log.debug("Error converting XML value to int: %s", e) ret = val elif self._is_yesno: if val == "yes": @@ -392,7 +392,7 @@ class _XMLState(object): try: self.xmlapi = XMLAPI(parsexml) except Exception: - logging.debug("Error parsing xml=\n%s", parsexml) + log.debug("Error parsing xml=\n%s", parsexml) raise if not self.is_build: |