From c2c8db066e5497c222ce3d3a6458cad00760f9e8 Mon Sep 17 00:00:00 2001 From: Rusty Bird Date: Thu, 4 Feb 2021 13:10:19 +0000 Subject: [PATCH 1/4] log: remove orphaned LOGFILE variable --- qubes/log.py | 1 - qubes/tests/__init__.py | 1 - 2 files changed, 2 deletions(-) diff --git a/qubes/log.py b/qubes/log.py index 5a0934af..1bb780f5 100644 --- a/qubes/log.py +++ b/qubes/log.py @@ -35,7 +35,6 @@ FORMAT_LOG = '%(asctime)s %(message)s' FORMAT_DEBUG = '%(asctime)s ' \ '[%(processName)s %(module)s.%(funcName)s:%(lineno)d] %(name)s: %(message)s' LOGPATH = '/var/log/qubes' -LOGFILE = os.path.join(LOGPATH, 'qubes.log') formatter_console = logging.Formatter(FORMAT_CONSOLE) formatter_log = logging.Formatter(FORMAT_LOG) diff --git a/qubes/tests/__init__.py b/qubes/tests/__init__.py index 076135b5..03ddc86b 100644 --- a/qubes/tests/__init__.py +++ b/qubes/tests/__init__.py @@ -106,7 +106,6 @@ try: ['git', 'rev-parse', '--show-toplevel'], stderr=subprocess.DEVNULL ).decode().strip() qubes.log.LOGPATH = '/tmp' - qubes.log.LOGFILE = '/tmp/qubes.log' except subprocess.CalledProcessError: # git returned nonzero, we are outside git repo pass From bb6e73c43e194bfde1961f2613d51f7e99fab101 Mon Sep 17 00:00:00 2001 From: Rusty Bird Date: Thu, 4 Feb 2021 18:21:55 +0000 Subject: [PATCH 2/4] log: avoid qubesd restart on logrotate Fixes QubesOS/qubes-issues#5004 --- linux/system-config/logrotate-qubes | 3 --- qubes/log.py | 6 ++++-- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/linux/system-config/logrotate-qubes b/linux/system-config/logrotate-qubes index 168a656b..5daf1aeb 100644 --- a/linux/system-config/logrotate-qubes +++ b/linux/system-config/logrotate-qubes @@ -9,9 +9,6 @@ /var/log/qubes/qubes.log { create 0640 root qubes su root qubes - postrotate - /bin/systemctl restart qubesd.service >/dev/null 2>/dev/null || true - endscript } /var/log/qubes/vm-*.log { diff --git a/qubes/log.py b/qubes/log.py index 1bb780f5..b0a4e37e 100644 --- a/qubes/log.py +++ b/qubes/log.py @@ -24,6 +24,7 @@ See also: :py:attr:`qubes.vm.qubesvm.QubesVM.log` ''' import logging +import logging.handlers import os import sys import fcntl @@ -102,7 +103,8 @@ def enable(): log_path = '/tmp/qubes.log' old_umask = os.umask(0o007) try: - handler_log = logging.FileHandler(log_path, 'a', encoding='utf-8') + handler_log = logging.handlers.WatchedFileHandler( + log_path, 'a', encoding='utf-8') fcntl.fcntl(handler_log.stream.fileno(), fcntl.F_SETFD, fcntl.FD_CLOEXEC) finally: @@ -136,7 +138,7 @@ def get_vm_logger(vmname): return logger old_umask = os.umask(0o007) try: - handler = logging.FileHandler( + handler = logging.handlers.WatchedFileHandler( os.path.join(LOGPATH, 'vm-{}.log'.format(vmname))) fcntl.fcntl(handler.stream.fileno(), fcntl.F_SETFD, fcntl.FD_CLOEXEC) From 761d752363c451a82153d8fea13713028106ef99 Mon Sep 17 00:00:00 2001 From: Rusty Bird Date: Fri, 5 Feb 2021 18:39:16 +0000 Subject: [PATCH 3/4] log: remove unused DBusHandler --- qubes/log.py | 38 -------------------------------------- 1 file changed, 38 deletions(-) diff --git a/qubes/log.py b/qubes/log.py index b0a4e37e..6d0866e1 100644 --- a/qubes/log.py +++ b/qubes/log.py @@ -29,8 +29,6 @@ import os import sys import fcntl -import dbus - FORMAT_CONSOLE = '%(message)s' FORMAT_LOG = '%(asctime)s %(message)s' FORMAT_DEBUG = '%(asctime)s ' \ @@ -41,42 +39,6 @@ formatter_console = logging.Formatter(FORMAT_CONSOLE) formatter_log = logging.Formatter(FORMAT_LOG) formatter_debug = logging.Formatter(FORMAT_DEBUG) -class DBusHandler(logging.Handler): - '''Handler which displays records as DBus notifications''' - - #: mapping of loglevels to icons - app_icons = { - logging.ERROR: 'dialog-error', - logging.WARNING: 'dialog-warning', - logging.NOTSET: 'dialog-information', - } - - def __init__(self, *args, **kwargs): - super().__init__(*args, **kwargs) - - self._notify_object = dbus.SessionBus().get_object( - 'org.freedesktop.Notifications', '/org/freedesktop/Notifications') - - - def emit(self, record): - app_icon = self.app_icons[ - max(level for level in self.app_icons if level <= record.levelno)] - - try: - # https://developer.gnome.org/notification-spec/#command-notify - self._notify_object.Notify( - 'Qubes', # STRING app_name - 0, # UINT32 replaces_id - app_icon, # STRING app_icon - record.msg, # STRING summary - '', # STRING body - (), # ARRAY actions - {}, # DICT hints - 0, # INT32 timeout - dbus_interface='org.freedesktop.Notifications') - except dbus.DBusException: - pass - def enable(): '''Enable global logging From 7c5988f69686c3eb46b7016d5354e238881f3c2d Mon Sep 17 00:00:00 2001 From: Rusty Bird Date: Fri, 5 Feb 2021 18:39:17 +0000 Subject: [PATCH 4/4] log: don't write to qubes.log or vm-*.log, only stderr --- linux/system-config/logrotate-qubes | 9 ---- qubes/app.py | 2 +- qubes/log.py | 64 +++++++++-------------------- qubes/tests/__init__.py | 1 - 4 files changed, 20 insertions(+), 56 deletions(-) diff --git a/linux/system-config/logrotate-qubes b/linux/system-config/logrotate-qubes index 5daf1aeb..d8ac0187 100644 --- a/linux/system-config/logrotate-qubes +++ b/linux/system-config/logrotate-qubes @@ -5,12 +5,3 @@ /bin/systemctl restart qubes-qmemman.service >/dev/null 2>/dev/null || true endscript } - -/var/log/qubes/qubes.log { - create 0640 root qubes - su root qubes -} - -/var/log/qubes/vm-*.log { - su root qubes -} diff --git a/qubes/app.py b/qubes/app.py index 5f0cd97c..ce0e029e 100644 --- a/qubes/app.py +++ b/qubes/app.py @@ -1486,7 +1486,7 @@ class Qubes(qubes.PropertyHolder): raise qubes.exc.QubesVMInUseError( vm, 'Domain is in use: {!r};' - 'see /var/log/qubes/qubes.log in dom0 for ' + "see 'journalctl -u qubesd -e' in dom0 for " 'details'.format( vm.name)) except AttributeError: diff --git a/qubes/log.py b/qubes/log.py index 6d0866e1..938925cf 100644 --- a/qubes/log.py +++ b/qubes/log.py @@ -24,20 +24,23 @@ See also: :py:attr:`qubes.vm.qubesvm.QubesVM.log` ''' import logging -import logging.handlers -import os import sys -import fcntl -FORMAT_CONSOLE = '%(message)s' -FORMAT_LOG = '%(asctime)s %(message)s' -FORMAT_DEBUG = '%(asctime)s ' \ - '[%(processName)s %(module)s.%(funcName)s:%(lineno)d] %(name)s: %(message)s' -LOGPATH = '/var/log/qubes' -formatter_console = logging.Formatter(FORMAT_CONSOLE) -formatter_log = logging.Formatter(FORMAT_LOG) -formatter_debug = logging.Formatter(FORMAT_DEBUG) +class Formatter(logging.Formatter): + def __init__(self, *args, debug=False, **kwargs): + super().__init__(*args, **kwargs) + self.debug = debug + + def formatMessage(self, record): + fmt = '' + if self.debug: + fmt += '[%(processName)s %(module)s.%(funcName)s:%(lineno)d] ' + if self.debug or record.name.startswith('vm.'): + fmt += '%(name)s: ' + fmt += '%(message)s' + + return fmt % record.__dict__ def enable(): @@ -55,25 +58,9 @@ def enable(): return handler_console = logging.StreamHandler(sys.stderr) - handler_console.setFormatter(formatter_console) + handler_console.setFormatter(Formatter()) logging.root.addHandler(handler_console) - if os.path.exists('/var/log/qubes'): - log_path = '/var/log/qubes/qubes.log' - else: - # for tests, travis etc - log_path = '/tmp/qubes.log' - old_umask = os.umask(0o007) - try: - handler_log = logging.handlers.WatchedFileHandler( - log_path, 'a', encoding='utf-8') - fcntl.fcntl(handler_log.stream.fileno(), - fcntl.F_SETFD, fcntl.FD_CLOEXEC) - finally: - os.umask(old_umask) - handler_log.setFormatter(formatter_log) - logging.root.addHandler(handler_log) - logging.root.setLevel(logging.INFO) def enable_debug(): @@ -83,10 +70,11 @@ def enable_debug(): ''' enable() - logging.root.setLevel(logging.DEBUG) for handler in logging.root.handlers: - handler.setFormatter(formatter_debug) + handler.setFormatter(Formatter(debug=True)) + + logging.root.setLevel(logging.DEBUG) def get_vm_logger(vmname): '''Initialise logging for particular VM name @@ -95,18 +83,4 @@ def get_vm_logger(vmname): :rtype: :py:class:`logging.Logger` ''' - logger = logging.getLogger('vm.' + vmname) - if logger.handlers: - return logger - old_umask = os.umask(0o007) - try: - handler = logging.handlers.WatchedFileHandler( - os.path.join(LOGPATH, 'vm-{}.log'.format(vmname))) - fcntl.fcntl(handler.stream.fileno(), - fcntl.F_SETFD, fcntl.FD_CLOEXEC) - finally: - os.umask(old_umask) - handler.setFormatter(formatter_log) - logger.addHandler(handler) - - return logger + return logging.getLogger('vm.' + vmname) diff --git a/qubes/tests/__init__.py b/qubes/tests/__init__.py index 03ddc86b..6b736626 100644 --- a/qubes/tests/__init__.py +++ b/qubes/tests/__init__.py @@ -105,7 +105,6 @@ try: in_git = subprocess.check_output( ['git', 'rev-parse', '--show-toplevel'], stderr=subprocess.DEVNULL ).decode().strip() - qubes.log.LOGPATH = '/tmp' except subprocess.CalledProcessError: # git returned nonzero, we are outside git repo pass