def test_no_duplicate_ua_handlers(self, m_getuid, m_config, logging_sandbox, tmpdir, FakeConfig): log_file = tmpdir.join("file.log") cfg = FakeConfig({"log_file": log_file.strpath}) m_config.return_value = cfg root_logger = logging.getLogger() setup_logging(logging.INFO, logging.DEBUG) stream_handlers = [ h for h in root_logger.handlers if h.level == logging.INFO and isinstance(h, logging.StreamHandler) ] file_handlers = [ h for h in root_logger.handlers if h.level == logging.DEBUG and isinstance(h, logging.FileHandler) and h.stream.name == log_file ] assert len(root_logger.handlers) == 2 assert len(stream_handlers) == 1 assert len(file_handlers) == 1 setup_logging(logging.INFO, logging.DEBUG) stream_handlers = [ h for h in root_logger.handlers if h.level == logging.INFO and isinstance(h, logging.StreamHandler) ] file_handlers = [ h for h in root_logger.handlers if h.level == logging.DEBUG and isinstance(h, logging.FileHandler) and h.stream.name == log_file ] assert len(root_logger.handlers) == 2 assert len(stream_handlers) == 1 assert len(file_handlers) == 1
def test_file_log_not_configured_if_not_root(self, m_getuid, tmpdir, logging_sandbox): log_file = tmpdir.join("log_file") setup_logging(logging.INFO, logging.INFO, log_file=log_file.strpath) logging.info("after setup") assert not log_file.exists()
def test_console_log_configured_if_not_present(self, level, capsys, logging_sandbox): setup_logging(level, logging.INFO) logging.log(level, "after setup") logging.log(level - 1, "not present") _, err = capsys.readouterr() assert "after setup" in err assert "not present" not in err
def test_disable_log_to_console_does_nothing_at_debug_level( self, logging_sandbox, capsys): cli.setup_logging(logging.DEBUG, logging.DEBUG) with util.disable_log_to_console(): logging.error("test error") logging.info("test info") out, err = capsys.readouterr() combined_output = out + err assert "test error" in combined_output assert "test info" in combined_output
def test_console_log_configured_if_already_present(self, capsys, logging_sandbox): logging.getLogger().addHandler(logging.StreamHandler(sys.stderr)) logging.error("before setup") setup_logging(logging.INFO, logging.INFO) logging.error("after setup") # 'before setup' will be in stderr, so check that setup_logging # configures the format _, err = capsys.readouterr() assert "ERROR: before setup" not in err assert "ERROR: after setup" in err
def test_file_log_configured_if_root(self, m_config, _m_getuid, log_filename, logging_sandbox, tmpdir): if log_filename is None: log_filename = "default.log" log_file = tmpdir.join(log_filename) m_config.CONFIG_DEFAULTS = {"log_file": log_file.strpath} else: log_file = tmpdir.join(log_filename) setup_logging(logging.INFO, logging.INFO, log_file=log_file.strpath) logging.info("after setup") assert "after setup" in log_file.read()
def test_custom_logger_configuration(self, m_getuid, m_config, logging_sandbox, tmpdir, FakeConfig): log_file = tmpdir.join("file.log") cfg = FakeConfig({"log_file": log_file.strpath}) m_config.return_value = cfg custom_logger = logging.getLogger("for-my-special-module") root_logger = logging.getLogger() n_root_handlers = len(root_logger.handlers) setup_logging(logging.INFO, logging.INFO, logger=custom_logger) assert len(custom_logger.handlers) == 2 assert len(root_logger.handlers) == n_root_handlers
def process_contract_delta_after_apt_lock() -> None: setup_logging(logging.INFO, logging.DEBUG) logging.debug("Check whether to upgrade-lts-contract") if not UAConfig().is_attached: logging.debug("Skiping upgrade-lts-contract. Machine is unattached") return out, _err = subp(["lsof", "/var/lib/apt/lists/lock"], rcs=[0, 1]) msg = "Starting upgrade-lts-contract." if out: msg += " Retrying every 10 seconds waiting on released apt lock" print(msg) logging.debug(msg) current_version = parse_os_release()["VERSION_ID"] current_release = version_to_codename[current_version] if current_release == "trusty": msg = "Unable to execute upgrade-lts-contract.py on trusty" print(msg) logging.warning(msg) sys.exit(1) past_release = current_codename_to_past_codename[current_release] past_entitlements = UAConfig(series=past_release).entitlements new_entitlements = UAConfig(series=current_release).entitlements retry_count = 0 while out: # Loop until that apt hold is released (at the end of the do-release-upgrade operation # when a reboot is suggested) time.sleep(10) out, _err = subp(["lsof", "/var/lib/apt/lists/lock"], rcs=[0, 1]) retry_count += 1 msg = "upgrade-lts-contract processing contract deltas: {} -> {}".format( past_release, current_release) print(msg) logging.debug(msg) process_entitlements_delta( past_entitlements=past_entitlements, new_entitlements=new_entitlements, allow_enable=True, series_overrides=False, ) msg = "upgrade-lts-contract succeeded after {} retries".format(retry_count) print(msg) logging.debug(msg)
def test_file_log_configured_if_already_present(self, m_config, _m_getuid, logging_sandbox, tmpdir, FakeConfig): some_file = log_file = tmpdir.join("default.log") logging.getLogger().addHandler(logging.FileHandler(some_file.strpath)) log_file = tmpdir.join("file.log") cfg = FakeConfig({"log_file": log_file.strpath}) m_config.return_value = cfg logging.error("before setup") setup_logging(logging.INFO, logging.INFO) logging.error("after setup") content = log_file.read() assert "[ERROR]: before setup" not in content assert "[ERROR]: after setup" in content
def test_file_log_only_readable_by_root(self, m_config, _m_getuid, logging_sandbox, tmpdir, pre_existing): log_file = tmpdir.join("root-only.log") log_path = log_file.strpath if pre_existing: log_file.write("existing content\n") assert 0o600 != stat.S_IMODE(os.lstat(log_path).st_mode) setup_logging(logging.INFO, logging.INFO, log_file=log_path) logging.info("after setup") assert 0o600 == stat.S_IMODE(os.lstat(log_path).st_mode) log_content = log_file.read() assert "after setup" in log_content if pre_existing: assert "existing content" in log_content
def test_file_log_is_world_readable(self, m_config, _m_getuid, logging_sandbox, tmpdir, pre_existing): log_file = tmpdir.join("root-only.log") log_path = log_file.strpath expected_mode = 0o644 if pre_existing: expected_mode = 0o640 log_file.write("existing content\n") os.chmod(log_path, expected_mode) assert 0o644 != stat.S_IMODE(os.lstat(log_path).st_mode) setup_logging(logging.INFO, logging.INFO, log_file=log_path) logging.info("after setup") assert expected_mode == stat.S_IMODE(os.lstat(log_path).st_mode) log_content = log_file.read() assert "after setup" in log_content if pre_existing: assert "existing content" in log_content
def test_disable_log_to_console(self, logging_sandbox, capsys, disable_log): # This test is parameterised so that we are sure that the context # manager is suppressing the output, not some other config change cli.setup_logging(logging.INFO, logging.INFO) if disable_log: context_manager = util.disable_log_to_console else: context_manager = mock.MagicMock with context_manager(): logging.error("test error") logging.info("test info") out, err = capsys.readouterr() combined_output = out + err if disable_log: assert not combined_output else: assert "test error" in combined_output assert "test info" in combined_output
return # Already have version 0.1 from daily PPA logging.debug("Patching /var/lib/ubuntu-advantage/status.json schema") new_status["_schema_version"] = "0.1" new_status["account"] = { "name": new_status.pop("account", ""), "id": new_status.pop("account-id", ""), } new_status["contract"] = { "tech_support_level": new_status.pop("techSupportLevel", "n/a"), "name": new_status.pop("subscription", ""), "id": new_status.pop("subscription-id", ""), } if "configStatus" in new_status: new_status["execution_status"] = new_status.pop("configStatus") if "configStatusDetails" in new_status: new_status["execution_details"] = new_status.pop("configStatusDetails") try: status_content = json.dumps(new_status, cls=util.DatetimeAwareJSONEncoder) except ValueError as e: logging.debug( "Unable to patch /var/lib/ubuntu-advantage/status.json: {}".format( str(e))) util.write_file(status_file, status_content) if __name__ == "__main__": setup_logging(logging.INFO, logging.DEBUG) patch_status_json_schema_0_1( status_file="/var/lib/ubuntu-advantage/status.json")
continue # Skip job as expected next_run hasn't yet passed if job.run(cfg): # Persist last_run and next_run UTC-based times on job success. jobs_status[job.name] = { "last_run": current_time, "next_run": current_time + timedelta(seconds=job.run_interval_seconds(cfg)), } cfg.write_cache(key="jobs-status", content=jobs_status) if __name__ == "__main__": cfg = UAConfig() current_time = datetime.now(timezone.utc) # The ua-timer logger should log everything to its file setup_logging( logging.CRITICAL, logging.DEBUG, log_file=cfg.timer_log_file, logger=LOG, ) # Make sure the ua-timer logger does not generate double logging LOG.propagate = False # The root logger should log any error to the timer log file setup_logging(logging.CRITICAL, logging.ERROR, log_file=cfg.timer_log_file) run_jobs(cfg=cfg, current_time=current_time)
except Exception as e: msg = "Failed running commands on reboot." msg += str(e) logging.error(msg) cfg.add_notice("", messages.REBOOT_SCRIPT_FAILED) def main(cfg): """Retry running process_reboot_operations on LockHeldError :raises: LockHeldError when lock still held by auto-attach after retries. UserFacingError for all other errors """ try: with lock.SpinLock( cfg=cfg, lock_holder="ua-reboot-cmds", sleep_time=SLEEP_ON_LOCK_HELD, max_retries=MAX_RETRIES_ON_LOCK_HELD, ): process_reboot_operations(cfg=cfg) except exceptions.LockHeldError as e: logging.warning("Lock not released. %s", str(e.msg)) sys.exit(1) if __name__ == "__main__": cfg = config.UAConfig() setup_logging(logging.INFO, logging.DEBUG, log_file=cfg.log_file) main(cfg=cfg)