def test_initialize_logger_defaultFilename(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) self.assertEquals(['host', 'start_time', 'tool', 'user'], sorted(logger._logging_dict.keys())) self.assertEquals("jacquard.log", os.path.basename(logger.log_filename))
def test_initialize_logger_createsParentDirs(self): with TempDirectory() as base_dir: tool = "foo" log_filename = os.path.join(base_dir.path, "tmp", "log.foo") args = Namespace(subparser_name=tool, log_file=log_filename, verbose=None) logger.initialize_logger(args) self.assertTrue(os.path.isdir(os.path.dirname(log_filename)))
def test_initialize_logger_notVerbose(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) logger.debug("bar") output_lines = self.output.getvalue().rstrip().split("\n") root_logger = logger.logging.getLogger() self.assertEquals(["root: DEBUG: bar"], root_logger.handlers[0].buffer) self.assertEquals(output_lines[0], "")
def test_initialize_logger_suppliedFilename(self): with TempDirectory() as base_dir: tool = "foo" log_filename = os.path.join(base_dir.path, "tmp", "log.foo") args = Namespace(subparser_name=tool, log_file=log_filename, verbose=None) logger.initialize_logger(args) self.assertEquals(['host', 'start_time', 'tool', 'user'], sorted(logger._logging_dict.keys())) self.assertEquals(log_filename, logger.log_filename)
def test_initialize_logger_createsParentDirs(self): try: tool = "foo" log_filename = "tmp/log.foo" args = Namespace(subparser_name=tool, log_file=log_filename, verbose=None) logger.initialize_logger(args) self.assertTrue(os.path.isdir(os.path.dirname(log_filename))) finally: shutil.rmtree(os.path.dirname(log_filename))
def test_noExceptionOnMalformedMessage(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) logger.info("bar {}/{}/{}", "1", "2") root_logger = logger.logging.getLogger() self.assertEquals(["root: INFO: Malformed log message (IndexError: tuple index out of range)|bar {}/{}/{}|['1', '2']"], root_logger.handlers[0].buffer)
def test_noExceptionOnMalformedMessage(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) logger.info("bar {}/{}/{}", "1", "2") root_logger = logger.logging.getLogger() errmsg = root_logger.handlers[0].buffer[0] self.assertRegexpMatches( r"root: INFO: Malformed log message .*\|bar {}/{}/{}\|['1', '2']", errmsg)
def test_initialize_logger_suppliedFilename(self): try: tool = "foo" log_filename = "tmp/log.foo" args = Namespace(subparser_name=tool, log_file=log_filename, verbose=None) logger.initialize_logger(args) self.assertEquals(['host', 'start_time', 'tool', 'user'], sorted(logger._logging_dict.keys())) self.assertEquals(log_filename, logger.log_filename) finally: shutil.rmtree(os.path.dirname(log_filename))
def _dispatch(modules, arguments): try: command, args = _parse_command_line_args(modules, arguments) execution_context = _get_execution_context(arguments) logger.initialize_logger(args) logger.debug("Jacquard run begins") logger.debug("cwd|{}", os.getcwd()) logger.debug("command|{}", " ".join(arguments)) command_validator.preflight(command, args) logger.info("Jacquard begins (v{})", __version__) logger.info("Saving log to [{}]", os.path.basename(logger.log_filename)) logger.debug("Writing output to tmp directory [{}]", args.temp_working_dir) command.execute(args, execution_context) _move_tmp_contents_to_original(args) if logger.WARNING_OCCURRED: logger.info("Done. (See warnings above)") else: logger.info("Done") except utils.UsageError as usage_error: message = "Jacquard usage problem: {}".format(str(usage_error)) logger.debug(message) print(message, file=sys.stderr) try: print("See 'jacquard {} --help'.".format(args.subparser_name), file=sys.stderr) except NameError: #could not determine the command print("See 'jacquard --help'.", file=sys.stderr) sys.exit(1) except Exception as exception: #pylint: disable=broad-except logger.error(str(exception)) logger.error("Jacquard encountered an unanticipated problem. " "Please review log file and contact your sysadmin " "or Jacquard support for assistance.") logger.debug(traceback.format_exc()) sys.exit(1) finally: try: _cleanup(args.temp_working_dir) except Exception: #pylint: disable=broad-except pass #we tried
def test_initialize_logger_verbose(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=True) logger.initialize_logger(args) logger.debug("bar") root_logger = logger.logging.getLogger() current_time = datetime.now().strftime('%Y-%m-%d') output_lines = self.output.getvalue().rstrip().split("\n") self.assertRegexpMatches(output_lines[0], "" + current_time + r".*\|DEBUG\|foo\|bar") self.assertEquals(["root: DEBUG: bar"], root_logger.handlers[0].buffer) self.assertRegexpMatches(output_lines[0], r"" + current_time + "|DEBUG|foo|bar'")
def test_initialize_logger_verbose(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=True) logger.initialize_logger(args) logger.debug("bar") root_logger = logger.logging.getLogger() current_time = datetime.now().strftime('%Y-%m-%d') output_lines = self.output.getvalue().rstrip().split("\n") self.assertRegexpMatches(output_lines[0], ""+current_time+r".*\|DEBUG\|foo\|bar") self.assertEquals(["root: DEBUG: bar"], root_logger.handlers[0].buffer) self.assertRegexpMatches(output_lines[0], r""+current_time+"|DEBUG|foo|bar'")
def test_warning(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) self.assertFalse(logger.WARNING_OCCURRED) logger.warning("bar") self.assertTrue(logger.WARNING_OCCURRED) root_logger = logger.logging.getLogger() current_time = datetime.now().strftime('%Y-%m-%d') output_lines = self.output.getvalue().rstrip().split("\n") self.assertEquals(["root: WARNING: bar"], root_logger.handlers[0].buffer) self.assertRegexpMatches(output_lines[0], "" + current_time + r".*\|WARNING\|foo\|bar")
def test_error(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) logger.error("bar") root_logger = logger.logging.getLogger() current_time = datetime.now().strftime('%Y-%m-%d') output_lines = self.output.getvalue().rstrip().split("\n") ##nosetests overwrites logger.FileHandler self.assertEquals(["root: ERROR: bar"], root_logger.handlers[0].buffer) self.assertRegexpMatches(output_lines[0], "" + current_time + r".*\|ERROR\|foo\|bar")
def test_warning(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) self.assertFalse(logger.WARNING_OCCURRED) logger.warning("bar") self.assertTrue(logger.WARNING_OCCURRED) root_logger = logger.logging.getLogger() current_time = datetime.now().strftime('%Y-%m-%d') output_lines = self.output.getvalue().rstrip().split("\n") self.assertEquals(["root: WARNING: bar"], root_logger.handlers[0].buffer) self.assertRegexpMatches(output_lines[0], ""+current_time+r".*\|WARNING\|foo\|bar")
def test_error(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) logger.error("bar") root_logger = logger.logging.getLogger() current_time = datetime.now().strftime('%Y-%m-%d') output_lines = self.output.getvalue().rstrip().split("\n") ##nosetests overwrites logger.FileHandler self.assertEquals(["root: ERROR: bar"], root_logger.handlers[0].buffer) self.assertRegexpMatches(output_lines[0], ""+current_time+r".*\|ERROR\|foo\|bar")
def test_info(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) current_time = datetime.now() logger.info("bar") root_logger = logger.logging.getLogger() self.assertEquals(["root: INFO: bar"], root_logger.handlers[0].buffer) output_lines = self.output.getvalue().rstrip().split("\n") self.assertEquals(len(output_lines), 1) log_fields = output_lines[0].split("|") self.assertEquals(4, len(log_fields)) log_time_string = log_fields[0] log_datetime = datetime.strptime(log_time_string, "%Y-%m-%d %H:%M:%S") seconds_delta = (log_datetime - current_time).total_seconds() self.assertLess(seconds_delta, 1) self.assertEquals(["INFO", "foo", "bar"], log_fields[1:])
def test_info_message_args(self): tool = "foo" args = Namespace(subparser_name=tool, log_file=None, verbose=None) logger.initialize_logger(args) current_time = datetime.now() logger.info("bar {}/{}", "1", "2") root_logger = logger.logging.getLogger() self.assertEquals(["root: INFO: bar 1/2"], root_logger.handlers[0].buffer) output_lines = self.output.getvalue().rstrip().split("\n") self.assertEquals(len(output_lines), 1) log_fields = output_lines[0].split("|") self.assertEquals(4, len(log_fields)) log_time_string = log_fields[0] log_datetime = datetime.strptime(log_time_string, "%Y-%m-%d %H:%M:%S") seconds_delta = (log_datetime - current_time).total_seconds() self.assertLess(seconds_delta, 1) self.assertEquals(["INFO", "foo", "bar 1/2"], log_fields[1:])