From c6c5f0e19aa82a51c34851dda40bbbf2bf92bef4 Mon Sep 17 00:00:00 2001 From: Christoph Kuhnke Date: Fri, 17 Nov 2023 14:06:51 +0100 Subject: [PATCH] #63 improved logging of ansible tasks (#64) #63 improved logging of ansible tasks Display duration of Ansible tasks. Display Ansible messages and error for failing fixtures in ci build. Installed rsync to enable replacing up ansible copy by faster synchronize. --- .github/workflows/check_ci.yaml | 3 +- doc/changes/changes_0.1.0.md | 2 ++ .../ds/sandbox/lib/ansible/ansible_access.py | 27 ++++++++++---- .../ds/sandbox/lib/ansible/ansible_runner.py | 35 ++++++++++++++++--- .../runtime/ansible/general_setup_tasks.yml | 3 ++ .../ansible/roles/jupyter/defaults/main.yml | 3 +- .../ansible/roles/jupyter/tasks/tutorial.yml | 5 +-- .../ansible/roles/rsync/defaults/main.yml | 4 +++ .../ansible/roles/rsync/tasks/main.yml | 6 ++++ .../test_create_dss_docker_image.py | 2 ++ test/unit/test_ansible.py | 9 +++-- 11 files changed, 80 insertions(+), 19 deletions(-) create mode 100644 exasol/ds/sandbox/runtime/ansible/roles/rsync/defaults/main.yml create mode 100644 exasol/ds/sandbox/runtime/ansible/roles/rsync/tasks/main.yml diff --git a/.github/workflows/check_ci.yaml b/.github/workflows/check_ci.yaml index 1746a941..c876d6fb 100644 --- a/.github/workflows/check_ci.yaml +++ b/.github/workflows/check_ci.yaml @@ -19,8 +19,7 @@ jobs: - name: Run pytest run: > - poetry run pytest - -o log_cli=true + poetry run pytest -o log_cli=true -o log_cli_level=INFO test/unit test/integration/test_create_dss_docker_image.py env: # Set the secret as an env variable diff --git a/doc/changes/changes_0.1.0.md b/doc/changes/changes_0.1.0.md index 3f18b15e..a05bb264 100644 --- a/doc/changes/changes_0.1.0.md +++ b/doc/changes/changes_0.1.0.md @@ -24,11 +24,13 @@ Version: 0.1.0 ## Bug Fixes * #1: Fixed CI build +* #61: Change initial password of Jupyter notebooks to "dss" ## Refactoring * #5: Renamed all occurrences of "script language developer" by "data science" * #56: Moved jupyter notebook files again +* #63: Improved logging of Ansible tasks ## Documentation diff --git a/exasol/ds/sandbox/lib/ansible/ansible_access.py b/exasol/ds/sandbox/lib/ansible/ansible_access.py index f653c7db..3e07cd28 100644 --- a/exasol/ds/sandbox/lib/ansible/ansible_access.py +++ b/exasol/ds/sandbox/lib/ansible/ansible_access.py @@ -1,7 +1,9 @@ import ansible_runner +import json import logging -from typing import Callable +from dataclasses import dataclass +from typing import Callable, Dict, Optional from exasol.ds.sandbox.lib.ansible.ansible_run_context import AnsibleRunContext from exasol.ds.sandbox.lib.logging import get_status_logger, LogType @@ -11,19 +13,30 @@ class AnsibleException(RuntimeError): pass +AnsibleEvent = Dict[str, any] + + class AnsibleAccess: """ Provides access to ansible runner. @raises: AnsibleException if ansible execution fails """ @staticmethod - def run(private_data_dir: str, run_ctx: AnsibleRunContext, printer: Callable[[str], None]): + def run( + private_data_dir: str, + run_ctx: AnsibleRunContext, + event_logger: Callable[[str], None], + event_handler: Callable[[AnsibleEvent], bool] = None, + ): quiet = not get_status_logger(LogType.ANSIBLE).isEnabledFor(logging.INFO) - r = ansible_runner.run(private_data_dir=private_data_dir, - playbook=run_ctx.playbook, - quiet=quiet, - extravars=run_ctx.extra_vars) + r = ansible_runner.run( + private_data_dir=private_data_dir, + playbook=run_ctx.playbook, + quiet=quiet, + event_handler=event_handler, + extravars=run_ctx.extra_vars, + ) for e in r.events: - printer(e) + event_logger(json.dumps(e, indent=2)) if r.rc != 0: raise AnsibleException(r.rc) diff --git a/exasol/ds/sandbox/lib/ansible/ansible_runner.py b/exasol/ds/sandbox/lib/ansible/ansible_runner.py index a1e492ee..b3165d9f 100644 --- a/exasol/ds/sandbox/lib/ansible/ansible_runner.py +++ b/exasol/ds/sandbox/lib/ansible/ansible_runner.py @@ -1,7 +1,9 @@ +import logging + from pathlib import Path from typing import Tuple -from exasol.ds.sandbox.lib.ansible.ansible_access import AnsibleAccess +from exasol.ds.sandbox.lib.ansible.ansible_access import AnsibleAccess, AnsibleEvent from exasol.ds.sandbox.lib.ansible.ansible_run_context import AnsibleRunContext from exasol.ds.sandbox.lib.logging import get_status_logger, LogType from exasol.ds.sandbox.lib.setup_ec2.host_info import HostInfo @@ -17,13 +19,36 @@ class AnsibleRunner: def __init__(self, ansible_access: AnsibleAccess, work_dir: Path): self._ansible_access = ansible_access self._work_dir = work_dir + self._duration_logger = AnsibleRunner.duration_logger() + + @classmethod + def duration_logger(cls) -> logging.Logger: + def handler(): + handler = logging.StreamHandler() + handler.setFormatter(logging.Formatter('%(message)s')) + return handler + logger = logging.getLogger(f"{__name__}:{cls.__name__}") + logger.setLevel(logging.DEBUG) + logger.propagate = False + logger.addHandler(handler()) + return logger - @staticmethod - def printer(msg: str): - LOG.debug(msg) + def event_handler(self, event: AnsibleEvent) -> bool: + if not "event_data" in event: + return True + duration = event["event_data"].get("duration", 0) + if duration > 0.5: + self._duration_logger.debug(f"duration: {round(duration)} seconds") + return True def run(self, ansible_run_context: AnsibleRunContext, host_infos: Tuple[HostInfo]): inventory_content = render_template("inventory.jinja", host_infos=host_infos) with open(self._work_dir / "inventory", "w") as f: f.write(inventory_content) - self._ansible_access.run(str(self._work_dir), ansible_run_context, self.printer) + event_handler = self.event_handler if LOG.isEnabledFor(logging.INFO) else None + self._ansible_access.run( + str(self._work_dir), + ansible_run_context, + event_logger=LOG.debug, + event_handler=self.event_handler, + ) diff --git a/exasol/ds/sandbox/runtime/ansible/general_setup_tasks.yml b/exasol/ds/sandbox/runtime/ansible/general_setup_tasks.yml index 132405d5..d3d121f6 100644 --- a/exasol/ds/sandbox/runtime/ansible/general_setup_tasks.yml +++ b/exasol/ds/sandbox/runtime/ansible/general_setup_tasks.yml @@ -3,6 +3,9 @@ upgrade: yes update_cache: yes become: "{{need_sudo}}" +- name: Install rsync + include_role: + name: rsync - name: Install Poetry include_role: name: poetry diff --git a/exasol/ds/sandbox/runtime/ansible/roles/jupyter/defaults/main.yml b/exasol/ds/sandbox/runtime/ansible/roles/jupyter/defaults/main.yml index 5456fc56..851ea369 100644 --- a/exasol/ds/sandbox/runtime/ansible/roles/jupyter/defaults/main.yml +++ b/exasol/ds/sandbox/runtime/ansible/roles/jupyter/defaults/main.yml @@ -5,8 +5,9 @@ jupyterlab: ip: '*' config: "{{user_home}}/.jupyter/jupyter_lab_config.py" virtualenv: "{{user_home}}/jupyterenv" - password: "{{ lookup('ansible.builtin.env', 'JUPYTER_LAB_PASSWORD', default='script-languages') }}" + password: "{{ lookup('ansible.builtin.env', 'JUPYTER_LAB_PASSWORD', default='dss') }}" notebook_folder: "{{user_home}}/notebooks" apt_dependencies: + - rsync=3.1.3-8ubuntu0.7 - virtualenv=20.0.17-1ubuntu0.4 diff --git a/exasol/ds/sandbox/runtime/ansible/roles/jupyter/tasks/tutorial.yml b/exasol/ds/sandbox/runtime/ansible/roles/jupyter/tasks/tutorial.yml index 17d516ff..a01b809c 100644 --- a/exasol/ds/sandbox/runtime/ansible/roles/jupyter/tasks/tutorial.yml +++ b/exasol/ds/sandbox/runtime/ansible/roles/jupyter/tasks/tutorial.yml @@ -1,6 +1,7 @@ --- - name: Copy notebook content - ansible.builtin.copy: + ansible.builtin.synchronize: src: "notebook/" dest: "{{jupyterlab.notebook_folder}}" - mode: 0644 + rsync_opts: + - "--chmod=0644" diff --git a/exasol/ds/sandbox/runtime/ansible/roles/rsync/defaults/main.yml b/exasol/ds/sandbox/runtime/ansible/roles/rsync/defaults/main.yml new file mode 100644 index 00000000..8d6a24cc --- /dev/null +++ b/exasol/ds/sandbox/runtime/ansible/roles/rsync/defaults/main.yml @@ -0,0 +1,4 @@ +--- + +apt_dependencies: + - rsync=3.1.3-8ubuntu0.7 diff --git a/exasol/ds/sandbox/runtime/ansible/roles/rsync/tasks/main.yml b/exasol/ds/sandbox/runtime/ansible/roles/rsync/tasks/main.yml new file mode 100644 index 00000000..ad88d557 --- /dev/null +++ b/exasol/ds/sandbox/runtime/ansible/roles/rsync/tasks/main.yml @@ -0,0 +1,6 @@ +- name: Install rsync + apt: + name: "{{apt_dependencies}}" + state: latest + update_cache: true + become: "{{need_sudo}}" diff --git a/test/integration/test_create_dss_docker_image.py b/test/integration/test_create_dss_docker_image.py index d306ab2c..fd35ca32 100644 --- a/test/integration/test_create_dss_docker_image.py +++ b/test/integration/test_create_dss_docker_image.py @@ -1,7 +1,9 @@ import docker +import io import pytest import re import requests +import sys import tenacity import time import typing diff --git a/test/unit/test_ansible.py b/test/unit/test_ansible.py index 251cc87e..ea27cfc0 100644 --- a/test/unit/test_ansible.py +++ b/test/unit/test_ansible.py @@ -8,6 +8,7 @@ AnsibleResourceRepository from exasol.ds.sandbox.lib.ansible.ansible_run_context import AnsibleRunContext, \ default_ansible_run_context +from exasol.ds.sandbox.lib.ansible.ansible_access import AnsibleEvent from exasol.ds.sandbox.lib.setup_ec2.host_info import HostInfo from exasol.ds.sandbox.lib.setup_ec2.run_install_dependencies import run_install_dependencies @@ -22,8 +23,12 @@ def __init__(self, delegate: Optional[Callable[[str, AnsibleRunContext], None]] self.arguments = namedtuple("Arguments", "private_data_dir run_ctx") self.delegate = delegate - def run(self, private_data_dir: str, run_ctx: AnsibleRunContext, printer: Callable[[str], None]): - + def run(self, + private_data_dir: str, + run_ctx: AnsibleRunContext, + event_handler: Callable[[AnsibleEvent], bool], + event_logger: Callable[[str], None], + ): self.call_arguments = self.arguments(private_data_dir, run_ctx) if self.delegate is not None: self.delegate(private_data_dir, run_ctx)