diff options
| author | Cole Robinson <crobinso@redhat.com> | 2019-06-16 21:12:39 -0400 |
|---|---|---|
| committer | Cole Robinson <crobinso@redhat.com> | 2019-06-17 00:12:31 -0400 |
| commit | f107e399890830780b2ac3c8a06c30b9da1c1d97 (patch) | |
| tree | 06260f80f989acbb9d8b81faf9ec393641656575 | |
| parent | 2c03ea5c9222955d1eba3fe3f308e55aa8c84461 (diff) | |
| download | virt-manager-f107e399890830780b2ac3c8a06c30b9da1c1d97.tar.gz | |
Switch to more traditional logging structure
Init a shared log instance in virtinst/logger.py, and use that
throughout the code base, so we aren't calling directly into
'logging'. This helps protect our logging output from being
cluttered with other library output, as happens with some
'requests' usage
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: |