From c803ce7c08465a3b4703b40f4238b1390eb367d9 Mon Sep 17 00:00:00 2001 From: Alice Ferrazzi Date: Sun, 17 Jun 2018 14:36:41 +0000 Subject: [PATCH] added logging functions for more clean output --- elivepatch_client/argsparser.py | 3 +- elivepatch_client/checkers.py | 9 ++- elivepatch_client/cli.py | 27 ++++--- elivepatch_client/log.py | 139 ++++++++++++++++++++++++++++++++ elivepatch_client/patch.py | 23 +++--- elivepatch_client/restful.py | 23 +++--- elivepatch_client/security.py | 3 +- 7 files changed, 188 insertions(+), 39 deletions(-) create mode 100644 elivepatch_client/log.py diff --git a/elivepatch_client/argsparser.py b/elivepatch_client/argsparser.py index c38af93..25f45bd 100644 --- a/elivepatch_client/argsparser.py +++ b/elivepatch_client/argsparser.py @@ -45,7 +45,8 @@ def __init__(self): parser.add_argument("-a","--kernel_version", help="set kernel version manually.") parser.add_argument("-l","--clear", action='store_true', help="Clear the already installed cve db (Use with caution!).") parser.add_argument("-u","--url", help="set elivepatch server url.") - parser.add_argument("-d","--debug", action='store_true', help="set the debug option.") + parser.add_argument("-d","--debug", help="set the debug option.") + parser.add_argument("-o","--log_output", help="set the debug option.") parser.add_argument("-v","--version", action='store_true', help="show the version.") self.args = parser.parse_args(remaining_argv) diff --git a/elivepatch_client/checkers.py b/elivepatch_client/checkers.py index 6bc5ecf..152d0d0 100644 --- a/elivepatch_client/checkers.py +++ b/elivepatch_client/checkers.py @@ -13,6 +13,7 @@ import re from elivepatch_client import restful +from elivepatch_client import log def id_generate_uuid(): @@ -33,7 +34,7 @@ def __init__(self, restserver_url, kernel_version, session_uuid=None): self.session_uuid = session_uuid else: self.session_uuid = id_generate_uuid() - print('This session uuid: ' + str(self.session_uuid)) + log.notice('This session uuid: ' + str(self.session_uuid)) self.rest_manager = restful.ManaGer(self.restserver_url, self.kernel_version, self.session_uuid) def set_config(self, config_fullpath): @@ -53,7 +54,7 @@ def send_files(self, incremental_patches_list): # check the configuration file # TODO: make it more compact if re.findall("[.]gz\Z", self.config_fullpath): - print('gz extension') + log.notice('gz extension') # uncompress the gzip config file # return configuration temporary folder temporary_config = f_action.decompress_gz(temporary_config) @@ -66,7 +67,7 @@ def send_files(self, incremental_patches_list): # Get kernel version from the configuration file header # self.kernel_version = f_action.config_kernel_version(temporary_config) self.rest_manager.set_kernel_version(self.kernel_version) - print('debug: kernel version = ' + self.rest_manager.get_kernel_version()) + log.notice('debug: kernel version = ' + self.rest_manager.get_kernel_version()) send_api = '/elivepatch/api/v1.0/get_files' @@ -91,7 +92,7 @@ def decompress_gz(self, temporary): :return: Uncompressed configuration file path """ path_gz_file = self.full_path - print('path_gz_file: '+ path_gz_file + ' temporary_path_uncompressed_file: ' + + log.notice('path_gz_file: '+ path_gz_file + ' temporary_path_uncompressed_file: ' + temporary.name) if os.path.isfile(path_gz_file): with gzip.open(path_gz_file, 'rb') as in_file: diff --git a/elivepatch_client/cli.py b/elivepatch_client/cli.py index f2fa2d9..c5b4c1f 100644 --- a/elivepatch_client/cli.py +++ b/elivepatch_client/cli.py @@ -13,6 +13,7 @@ from elivepatch_client.version import VERSION from elivepatch_client import patch from elivepatch_client import security +from elivepatch_client import log import tempfile if sys.hexversion >= 0x30200f0: @@ -28,21 +29,25 @@ class Main(object): def __init__(self, argparser): config = argparser.get_arg() + # Initialize the logger before anything else. + config.color = True + log.setup_logging(config.debug, output=config.log_output, debug=config.debug, +color=config.color) self.dispatch(config) def dispatch(self, config): - print(str(config)) + log.debug(str(config)) if config.cve: patch_manager = patch.ManaGer() applied_patches_list = patch_manager.list(config.kernel_version) - print(applied_patches_list) + log.notice(applied_patches_list) cve_repository = security.CVE() if not os.path.isdir("/tmp/kernel_cve"): - print("Downloading the CVE repository...") + log.notice("Downloading the CVE repository...") cve_repository.git_download() else: - print("CVE repository already present.") - print("updating...") + log.notice("CVE repository already present.") + log.notice("updating...") cve_repository.git_update() if config.clear: if os.path.isfile('cve_ids'): @@ -66,23 +71,23 @@ def dispatch(self, config): with shelve.open('cve_ids') as cve_db: cve_db[cve_id] = cve_patch - print('merging cve patches...') + log.notice('merging cve patches...') with tempfile.NamedTemporaryFile(dir='/tmp/', delete=False) as portage_tmpdir: - print('portage_tmpdir: '+portage_tmpdir.name) + log.notice('portage_tmpdir: '+portage_tmpdir.name) for cve_id, cve_file in cve_patch_list: with open(cve_file,'rb+') as infile: portage_tmpdir.write(infile.read()) livepatch(config.url, config.kernel_version, config.config, portage_tmpdir.name, applied_patches_list) - print(new_cve_patch_list) + log.notice(new_cve_patch_list) elif config.patch: patch_manager = patch.ManaGer() applied_patches_list = patch_manager.list(config.kernel_version) - print(applied_patches_list) + log.notice(str(applied_patches_list)) livepatch(config.url, config.kernel_version, config.config, config.patch, applied_patches_list) elif config.version: - print('elivepatch version: '+str(VERSION)) + log.notice('elivepatch version: '+str(VERSION)) else: print('--help for help\n\ you need at list --patch or --cve') @@ -105,4 +110,4 @@ def livepatch(url, kernel_version, config, main_patch, incremental_patch_names_l current_kernel.set_config(config) current_kernel.set_main_patch(main_patch) current_kernel.send_files(incremental_patch_names_list) - current_kernel.get_livepatch() \ No newline at end of file + current_kernel.get_livepatch() diff --git a/elivepatch_client/log.py b/elivepatch_client/log.py new file mode 100644 index 0000000..d931efe --- /dev/null +++ b/elivepatch_client/log.py @@ -0,0 +1,139 @@ +# Copyright 2003-2018 Gentoo Foundation +# Distributed under the terms of the GNU General Public License v2 + +"""Logging related code (taken from Gentoo Catalyst) +This largely exposes the same interface as the logging module except we add +another level "notice" between warning & info, and all output goes through +the "elivepatch" logger. +""" + +from __future__ import print_function + +import logging +import logging.handlers +import os +import sys +import time + + +class elivepatchLogger(logging.Logger): + """Override the _log member to autosplit on new lines""" + + def _log(self, level, msg, args, **kwargs): + """If given a multiline message, split it""" + # We have to interpolate it first in case they spread things out + # over multiple lines like: Bad Thing:\n%s\nGoodbye! + try: + msg %= args + for line in msg.splitlines(): + super(elivepatchLogger, self)._log(level, line, (), **kwargs) + except: + print("msg") + print(msg) + print("args") + print(args) + + +# The logger that all output should go through. +# This is ugly because we want to not perturb the logging module state. +_klass = logging.getLoggerClass() +logging.setLoggerClass(elivepatchLogger) +logger = logging.getLogger('elivepatch') +logging.setLoggerClass(_klass) +del _klass + + +# Set the notice level between warning and info. +NOTICE = (logging.WARNING + logging.INFO) // 2 +logging.addLevelName(NOTICE, 'NOTICE') + + +# The API we expose to consumers. +def notice(msg, *args, **kwargs): + """Log a notice message""" + logger.log(NOTICE, msg, *args, **kwargs) + +def critical(msg, *args, **kwargs): + """Log a critical message and then exit""" + status = kwargs.pop('status', 1) + logger.critical(msg, *args, **kwargs) + sys.exit(status) + +error = logger.error +warning = logger.warning +info = logger.info +debug = logger.debug + + +class elivepatchFormatter(logging.Formatter): + """Mark bad messages with colors automatically""" + + _COLORS = { + 'CRITICAL': '\033[1;35m', + 'ERROR': '\033[1;31m', + 'WARNING': '\033[1;33m', + 'DEBUG': '\033[1;34m', + } + _NORMAL = '\033[0m' + + @staticmethod + def detect_color(): + """Figure out whether the runtime env wants color""" + if 'NOCOLOR' is os.environ: + return False + return os.isatty(sys.stdout.fileno()) + + def __init__(self, *args, **kwargs): + """Initialize""" + color = kwargs.pop('color', None) + if color is None: + color = self.detect_color() + if not color: + self._COLORS = {} + + super(elivepatchFormatter, self).__init__(*args, **kwargs) + + def format(self, record, **kwargs): + """Format the |record| with our color settings""" + msg = super(elivepatchFormatter, self).format(record, **kwargs) + color = self._COLORS.get(record.levelname) + if color: + return color + msg + self._NORMAL + else: + return msg + + +# We define |debug| in global scope so people can call log.debug(), but it +# makes the linter complain when we have a |debug| keyword. Since we don't +# use that func in here, it's not a problem, so silence the warning. +# pylint: disable=redefined-outer-name +def setup_logging(level, output=None, debug=False, color=None): + """Initialize the logging module using the |level| level""" + # The incoming level will be things like "info", but setLevel wants + # the numeric constant. Convert it here. + try: + level = logging.getLevelName(level.upper()) + + # The good stuff. + fmt = '%(asctime)s: %(levelname)-8s: ' + if debug: + fmt += '%(filename)s:%(funcName)s: ' + fmt += '%(message)s' + + # Figure out where to send the log output. + if output is None: + handler = logging.StreamHandler(stream=sys.stdout) + else: + handler = logging.FileHandler(output) + + # Use a date format that is readable by humans & machines. + # Think e-mail/RFC 2822: 05 Oct 2013 18:58:50 EST + tzname = time.strftime('%Z', time.localtime()) + datefmt = '%d %b %Y %H:%M:%S ' + tzname + formatter = elivepatchFormatter(fmt, datefmt, color=color) + handler.setFormatter(formatter) + + logger.addHandler(handler) + logger.setLevel(level) + except: + pass diff --git a/elivepatch_client/patch.py b/elivepatch_client/patch.py index 3540e5a..3014832 100644 --- a/elivepatch_client/patch.py +++ b/elivepatch_client/patch.py @@ -2,6 +2,7 @@ import shutil import tempfile import subprocess +from elivepatch_client import log class ManaGer(object): @@ -36,9 +37,9 @@ def list(self, kernel_version): if filenames and not dirnames: for filename in filenames: if filename.endswith('.patch'): - print('dirpath: '+str(dirpath),'filename: '+str(filename)) + log.notice('dirpath: '+str(dirpath),'filename: '+str(filename)) incremental_patch_fullpath = os.path.join(dirpath, filename) - print(incremental_patch_fullpath) + log.notice(incremental_patch_fullpath) patch_filename.append(incremental_patch_fullpath) # os.walk() walks in random order, perform a lexical sort patch_filename.sort() @@ -48,9 +49,9 @@ def list(self, kernel_version): if filenames and not dirnames: for filename in filenames: if filename.endswith('.patch'): - print('dirpath: '+str(dirpath),'filename: '+str(filename)) + log.notice(str('dirpath: '+str(dirpath) + 'filename: '+str(filename))) incremental_patch_fullpath = os.path.join(dirpath, filename) - print(incremental_patch_fullpath) + log.notice(incremental_patch_fullpath) previous_patches.append(incremental_patch_fullpath) # os.walk() walks in random order, perform a lexical sort previous_patches = sorted(previous_patches, key=lambda elive: int(elive.replace('/elivepatch.patch','').split('_')[1])) @@ -58,7 +59,7 @@ def list(self, kernel_version): # Append the previous patches to the eapply_user patches list patch_filename.extend(previous_patches) - print('List of current patches:') + log.notice('List of current patches:') return patch_filename def load(self, patch_fulldir, livepatch_fulldir): @@ -69,10 +70,10 @@ def load(self, patch_fulldir, livepatch_fulldir): """ try: _command(['sudo', 'kpatch', 'load', livepatch_fulldir]) - print('patch_fulldir:' + str(patch_fulldir) + ' livepatch_fulldir: '+ str(livepatch_fulldir)) + log.notice('patch_fulldir:' + str(patch_fulldir) + ' livepatch_fulldir: '+ str(livepatch_fulldir)) self._save(patch_fulldir, livepatch_fulldir) except: - print('failed to load the livepatch') + log.notice('failed to load the livepatch') def _save(self, patch_fulldir, livepatch_fulldir): """ @@ -107,12 +108,12 @@ def _command(bashCommand, kernel_source_dir=None, env=None): env = process_env if kernel_source_dir: - print(bashCommand) + log.notice(bashCommand) process = subprocess.Popen(bashCommand, stdout=subprocess.PIPE, cwd=kernel_source_dir, env=env) output, error = process.communicate() - print(output) + log.notice(output) else: - print(bashCommand) + log.notice(bashCommand) process = subprocess.Popen(bashCommand, stdout=subprocess.PIPE, env=env) output, error = process.communicate() - print(output) + log.notice(output) diff --git a/elivepatch_client/restful.py b/elivepatch_client/restful.py index 73e3387..0afc899 100644 --- a/elivepatch_client/restful.py +++ b/elivepatch_client/restful.py @@ -7,8 +7,9 @@ import requests import os import shutil -from elivepatch_client import patch import tempfile +from elivepatch_client import patch +from elivepatch_client import log import sys from io import BytesIO @@ -42,7 +43,7 @@ def version(self): """ url = self.server_url + '/elivepatch/api/v1.0/agent' r = requests.get(url) - print(r.json()) + log.notice(r.json()) def send_files(self, temporary_config, new_patch_fullpath, incremental_patches, api): """ @@ -66,7 +67,7 @@ def send_files(self, temporary_config, new_patch_fullpath, incremental_patches, # Static patch and config filename files=[] counter = 0 - print('incremental_patches: '+str(incremental_patches)) + log.notice('incremental_patches: '+str(incremental_patches)) for incremental_patch_fullpath in incremental_patches: if incremental_patch_fullpath.endswith('.patch'): # TODO: we need to close what we open @@ -75,13 +76,13 @@ def send_files(self, temporary_config, new_patch_fullpath, incremental_patches, counter += 1 files.append(('main_patch', ('main.patch', open(new_patch_fullpath, 'rb'), 'multipart/form-data', {'Expires': '0'}))) files.append(('config', ('config', open(temporary_config.name, 'rb'), 'multipart/form-data', {'Expires': '0'}))) - print(str(files)) + log.notice(str(files)) try: response = requests.post(url, files=files, headers=headers) - print('send file: ' + str(response.json())) + log.notice('send file: ' + str(response.json())) response_dict = response.json() except requests.exceptions.ConnectionError as e: - print('connection error: %s' % e) + log.notice('connection error: %s' % e) temporary_config.close() except: self._catching_exceptions_exit(self.send_files) @@ -107,9 +108,9 @@ def get_livepatch(self, patch_folder): with open('myfile.ko', 'wb') as out: out.write(r.content) r.close() - print(b) + log.notice(b) except: - print('livepatch not found') + log.notice('livepatch not found') r.close() except: self._catching_exceptions_exit(self.get_livepatch) @@ -120,12 +121,12 @@ def get_livepatch(self, patch_folder): if not os.path.exists(elivepatch_uuid_dir): os.makedirs(elivepatch_uuid_dir) shutil.copy("myfile.ko", livepatch_fulldir) - print('livepatch saved in ' + elivepatch_uuid_dir + '/ folder') + log.notice('livepatch saved in ' + elivepatch_uuid_dir + '/ folder') patch_manager.load(patch_folder, livepatch_fulldir) else: - print('livepatch not received') + log.notice('livepatch not received') def _catching_exceptions_exit(self, current_function): e = sys.exc_info() - print( "Error %s: %s" % (current_function.__name__, str(e)) ) + log.error( "Error %s: %s" % (current_function.__name__, str(e)) ) sys.exit(1) diff --git a/elivepatch_client/security.py b/elivepatch_client/security.py index 45241e5..39f4071 100644 --- a/elivepatch_client/security.py +++ b/elivepatch_client/security.py @@ -1,6 +1,7 @@ import git import os import urllib.request as request +from elivepatch_client import log import shutil @@ -42,7 +43,7 @@ def cve_git_id(self, kernel_version): security_versions.append(security_versions_tmp.split('.')[2]) security_file.close() - print('[debug] security versions: ' + str(security_versions)) + log.notice('[debug] security versions: ' + str(security_versions)) cve_2d_list = [] for version in security_versions: