From b6dcadeae74455563996193bc54fac118fa44663 Mon Sep 17 00:00:00 2001 From: Andrei Stepanov Date: Jun 27 2018 10:55:54 +0000 Subject: Rewrite rpm/docker/local provisioners with using logging module. Signed-off-by: Andrei Stepanov --- diff --git a/inventory/standard-inventory-docker b/inventory/standard-inventory-docker index a35ca99..e834050 100755 --- a/inventory/standard-inventory-docker +++ b/inventory/standard-inventory-docker @@ -35,8 +35,45 @@ import sys import tempfile import time import distutils.util +import logging + EMPTY_INVENTORY = {} +LOG_FILE = "default_provisioners.log" + + +def get_artifact_path(path=""): + """Return path to an artifact file in artifacts directory. If path == "" + than return path artifacts dir. Create artifacts dir if necessary. + """ + artifacts = os.environ.get("TEST_ARTIFACTS", os.path.join(os.getcwd(), "artifacts")) + try: + os.makedirs(artifacts) + except OSError as exc: + if exc.errno != errno.EEXIST or not os.path.isdir(artifacts): + raise + return os.path.join(artifacts, path) + + +logger = logging.getLogger(__name__) +logger.setLevel(logging.DEBUG) +# stderr output +conhandler = logging.StreamHandler() +# Print to strerr by default messages with level >= warning, can be changed +# with setting TEST_DEBUG=1. +try: + diagnose = distutils.util.strtobool(os.getenv("TEST_DEBUG", "0")) +except ValueError: + diagnose = 0 +conhandler.setLevel(logging.WARNING) +if diagnose: + # Collect all messages with any log level to stderr. + conhandler.setLevel(logging.NOTSET) +# Log format for stderr. +log_format = "[%(levelname)-5.5s] {}: %(message)s".format(os.path.basename(__file__)) +formatter = logging.Formatter(log_format) +conhandler.setFormatter(formatter) +logger.addHandler(conhandler) def main(argv): @@ -47,19 +84,22 @@ def main(argv): default=os.environ.get("TEST_DOCKER_EXTRA_ARGS", "")) parser.add_argument("subjects", nargs="*", default=shlex.split(os.environ.get("TEST_SUBJECTS", ""))) opts = parser.parse_args() - - try: - if opts.host: - _, data = inv_host(opts.host, opts.docker_extra_args) - else: - data = inv_list(opts.subjects, opts.docker_extra_args) - sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': '))) - except RuntimeError as ex: - sys.stderr.write("{0}: {1}\n".format(os.path.basename(sys.argv[0]), str(ex))) - sys.stdout.write(json.dumps(EMPTY_INVENTORY, indent=4, separators=(',', ': '))) - return 1 - - return 0 + # Send logs to common logfile for all default provisioners. + log_file = get_artifact_path(LOG_FILE) + fhandler = logging.FileHandler(log_file) + # Collect all messages with any log level to log file. + fhandler.setLevel(logging.NOTSET) + log_format = ("%(asctime)s [{}/%(threadName)-12.12s] [%(levelname)-5.5s]:" + "%(message)s").format(os.path.basename(__file__)) + logFormatter = logging.Formatter(log_format) + fhandler.setFormatter(logFormatter) + logger.addHandler(fhandler) + logger.info("Start provisioner.") + if opts.host: + _, data = inv_host(opts.host, opts.docker_extra_args) + else: + data = inv_list(opts.subjects, opts.docker_extra_args) + sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': '))) def inv_list(subjects, docker_extra_args): @@ -93,20 +133,13 @@ def inv_host(subject, docker_extra_args): directory = tempfile.mkdtemp(prefix="inventory-docker") cidfile = os.path.join(directory, "cid") - - # Determine if container should be kept available for diagnosis after completion - try: - diagnose = distutils.util.strtobool(os.getenv("TEST_DEBUG", "0")) - except ValueError: - diagnose = 0 - # Check for any additional arguments to include when starting docker container try: extra_arg_list = shlex.split(docker_extra_args) except ValueError: raise RuntimeError("Could not parse DOCKER_EXTRA_ARGS") - sys.stderr.write("Launching Docker container for {0}\n".format(image)) + logger.info("Launching Docker container for {0}".format(image)) # Make sure the docker service is running cmd = [ @@ -150,7 +183,7 @@ def inv_host(subject, docker_extra_args): except subprocess.CalledProcessError: pass else: - sys.stderr.write("ERROR: Could not set ansible_python_interpreter") + logger.error("Could not set ansible_python_interpreter.") return None # Directory to place artifacts @@ -183,6 +216,7 @@ def inv_host(subject, docker_extra_args): os.dup2(tty, 2) # Now wait for the parent process to go away, then kill the VM + logger.info("docker exec -it {0} /bin/bash".format(name)) while True: time.sleep(3) @@ -192,13 +226,9 @@ def inv_host(subject, docker_extra_args): break # Either of the processes no longer exist if diagnose: - sys.stderr.write("\n") - sys.stderr.write("DIAGNOSE: docker exec -it {0} /bin/bash\n".format(name)) - sys.stderr.write("DIAGNOSE: kill {0} # when finished\n".format(os.getpid())) - def _signal_handler(*args): - sys.stderr.write("\nDIAGNOSE ending...\n") - + logger.info("Diagnose ending.") + logger.info("kill {0} # when finished".format(os.getpid())) signal.signal(signal.SIGTERM, _signal_handler) signal.pause() @@ -220,4 +250,11 @@ def inv_host(subject, docker_extra_args): if __name__ == '__main__': - sys.exit(main(sys.argv)) + ret = -1 + try: + main(sys.argv) + ret = 0 + except Exception: + # Backtrace stack goes to log file. If TEST_DEBUG == 1, it goes to stderr too. + logger.info("Fatal error in provision script.", exc_info=True) + sys.exit(ret) diff --git a/inventory/standard-inventory-local b/inventory/standard-inventory-local index 162b315..3376a5b 100755 --- a/inventory/standard-inventory-local +++ b/inventory/standard-inventory-local @@ -27,8 +27,47 @@ import argparse import json import os import sys +import logging +import errno +import distutils.util EMPTY_INVENTORY = {} +LOG_FILE = "default_provisioners.log" + + +def get_artifact_path(path=""): + """Return path to an artifact file in artifacts directory. If path == "" + than return path artifacts dir. Create artifacts dir if necessary. + """ + artifacts = os.environ.get("TEST_ARTIFACTS", os.path.join(os.getcwd(), "artifacts")) + try: + os.makedirs(artifacts) + except OSError as exc: + if exc.errno != errno.EEXIST or not os.path.isdir(artifacts): + raise + return os.path.join(artifacts, path) + + +logger = logging.getLogger(__name__) +logger.setLevel(logging.DEBUG) +# stderr output +conhandler = logging.StreamHandler() +# Print to strerr by default messages with level >= warning, can be changed +# with setting TEST_DEBUG=1. +try: + diagnose = distutils.util.strtobool(os.getenv("TEST_DEBUG", "0")) +except ValueError: + diagnose = 0 +conhandler.setLevel(logging.WARNING) +if diagnose: + # Collect all messages with any log level to stderr. + conhandler.setLevel(logging.NOTSET) +# Log format for stderr. + +log_format = "[%(levelname)-5.5s] {}: %(message)s".format(os.path.basename(__file__)) +formatter = logging.Formatter(log_format) +conhandler.setFormatter(formatter) +logger.addHandler(conhandler) def main(argv): @@ -36,19 +75,22 @@ def main(argv): parser.add_argument("--list", action="store_true", help="Verbose output") parser.add_argument('--host', help="Get host variables") opts = parser.parse_args() - - try: - if opts.host: - data = inv_host(opts.host) - else: - data = inv_list() - sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': '))) - except RuntimeError as ex: - sys.stderr.write("{0}: {1}\n".format(os.path.basename(sys.argv[0]), str(ex))) - sys.stdout.write(json.dumps(EMPTY_INVENTORY, indent=4, separators=(',', ': '))) - return 1 - - return 0 + # Send logs to common logfile for all default provisioners. + log_file = get_artifact_path(LOG_FILE) + fhandler = logging.FileHandler(log_file) + # Collect all messages with any log level to log file. + fhandler.setLevel(logging.NOTSET) + log_format = ("%(asctime)s [{}/%(threadName)-12.12s] [%(levelname)-5.5s]:" + "%(message)s").format(os.path.basename(__file__)) + logFormatter = logging.Formatter(log_format) + fhandler.setFormatter(logFormatter) + logger.addHandler(fhandler) + logger.info("Start provisioner.") + if opts.host: + data = inv_host(opts.host) + else: + data = inv_list() + sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': '))) def inv_list(): @@ -73,4 +115,11 @@ def inv_host(host): if __name__ == '__main__': - sys.exit(main(sys.argv)) + ret = -1 + try: + main(sys.argv) + ret = 0 + except Exception: + # Backtrace stack goes to log file. If TEST_DEBUG == 1, it goes to stderr too. + logger.info("Fatal error in provision script.", exc_info=True) + sys.exit(ret) diff --git a/inventory/standard-inventory-rpm b/inventory/standard-inventory-rpm index 739179a..e8bfbc2 100755 --- a/inventory/standard-inventory-rpm +++ b/inventory/standard-inventory-rpm @@ -30,8 +30,47 @@ import os import shlex import subprocess import sys +import logging +import errno +import distutils.util EMPTY_INVENTORY = {} +LOG_FILE = "default_provisioners.log" + + +def get_artifact_path(path=""): + """Return path to an artifact file in artifacts directory. If path == "" + than return path artifacts dir. Create artifacts dir if necessary. + """ + artifacts = os.environ.get("TEST_ARTIFACTS", os.path.join(os.getcwd(), "artifacts")) + try: + os.makedirs(artifacts) + except OSError as exc: + if exc.errno != errno.EEXIST or not os.path.isdir(artifacts): + raise + return os.path.join(artifacts, path) + + +logger = logging.getLogger(__name__) +logger.setLevel(logging.DEBUG) + +# stderr output +conhandler = logging.StreamHandler() +# Print to strerr by default messages with level >= warning, can be changed +# with setting TEST_DEBUG=1. +try: + diagnose = distutils.util.strtobool(os.getenv("TEST_DEBUG", "0")) +except ValueError: + diagnose = 0 +conhandler.setLevel(logging.WARNING) +if diagnose: + # Collect all messages with any log level to stderr. + conhandler.setLevel(logging.NOTSET) +# Log format for stderr. +log_format = "[%(levelname)-5.5s] {}: %(message)s".format(os.path.basename(__file__)) +formatter = logging.Formatter(log_format) +conhandler.setFormatter(formatter) +logger.addHandler(conhandler) def main(argv): @@ -40,19 +79,22 @@ def main(argv): parser.add_argument('--host', help="Get host variables") parser.add_argument("subjects", nargs="*", default=os.environ.get("TEST_SUBJECTS", "")) opts = parser.parse_args() - - try: - if opts.host: - data = gethost(opts.host) - else: - data = getlist(opts.subjects) - sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': '))) - except RuntimeError as ex: - sys.stderr.write("{0}: {1}\n".format(os.path.basename(sys.argv[0]), str(ex))) - sys.stdout.write(json.dumps(EMPTY_INVENTORY, indent=4, separators=(',', ': '))) - return 1 - - return 0 + # Send logs to common logfile for all default provisioners. + log_file = get_artifact_path(LOG_FILE) + fhandler = logging.FileHandler(log_file) + # Collect all messages with any log level to log file. + fhandler.setLevel(logging.NOTSET) + log_format = ("%(asctime)s [{}/%(threadName)-12.12s] [%(levelname)-5.5s]:" + "%(message)s").format(os.path.basename(__file__)) + logFormatter = logging.Formatter(log_format) + fhandler.setFormatter(logFormatter) + logger.addHandler(fhandler) + logger.info("Start provisioner.") + if opts.host: + data = gethost(opts.host) + else: + data = getlist(opts.subjects) + sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': '))) def getlist(subjects): @@ -120,4 +162,11 @@ def isrepo(subject): if __name__ == '__main__': - sys.exit(main(sys.argv)) + ret = -1 + try: + main(sys.argv) + ret = 0 + except Exception: + # Backtrace stack goes to log file. If TEST_DEBUG == 1, it goes to stderr too. + logger.info("Fatal error in provision script.", exc_info=True) + sys.exit(ret)