#63 improved logging of ansible tasks

.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

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
 

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)

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,
+        )

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

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

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"

exasol/ds/sandbox/runtime/ansible/roles/rsync/defaults/main.yml

@@ -0,0 +1,4 @@
+---
+
+apt_dependencies:
+  - rsync=3.1.3-8ubuntu0.7

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}}"

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

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)