From 9687a48742e384eb030f1e77e854950cdde569be Mon Sep 17 00:00:00 2001 From: Dennis Ploeger Date: Fri, 16 Aug 2024 13:46:20 +0200 Subject: [PATCH 1/5] feat: Make logging of dumps optional to work around max_line_size problem Includes better documentation and parameter support Includes test suite --- .github/workflows/test.yml | 34 +++++ loki.py | 247 ++++++++++++++++++++++-------------- test/ansible.cfg | 6 + test/default/inventory.yaml | 4 + test/default/playbook.yaml | 48 +++++++ test/playbook.yaml | 53 ++++++++ 6 files changed, 296 insertions(+), 96 deletions(-) create mode 100644 .github/workflows/test.yml create mode 100644 test/ansible.cfg create mode 100644 test/default/inventory.yaml create mode 100644 test/default/playbook.yaml create mode 100644 test/playbook.yaml diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml new file mode 100644 index 0000000..72736a2 --- /dev/null +++ b/.github/workflows/test.yml @@ -0,0 +1,34 @@ +# This workflow will install Python dependencies, run tests and lint with a single version of Python +# For more information see: https://docs.github.com/en/actions/automating-builds-and-tests/building-and-testing-python + +name: Python application + +on: + push: + branches: [ "main" ] + pull_request: + branches: [ "main" ] + +permissions: + contents: read + +jobs: + build: + + runs-on: ubuntu-latest + + steps: + - uses: actions/checkout@v4 + - name: Set up Python 3.10 + uses: actions/setup-python@v3 + with: + python-version: "3.10" + - name: Install dependencies + run: | + python -m pip install --upgrade pip + pip install -r requirements.txt -r requirements-dev.txt + - name: Run test + run: | + cd test + python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=20 -vvv + LOKI_ENABLED_DUMPS=play python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=26 -vvv \ No newline at end of file diff --git a/loki.py b/loki.py index 9d291d3..38bde7e 100644 --- a/loki.py +++ b/loki.py @@ -18,14 +18,59 @@ requirements: - set as loki in configuration options: + loki_url: + description: URL to access loki gateway + required: True + env: + - name: LOKI_URL + ini: + - section: loki + key: url + loki_username: + description: Username to access loki gateway + env: + - name: LOKI_USERNAME + ini: + - section: loki + key: username + loki_password: + description: Password to access loki gateway + env: + - name: LOKI_PASSWORD + ini: + - section: loki + key: password + loki_org_id: + description: Organization to use as a tenant when connecting to loki + env: + - name: LOKI_ORG_ID + ini: + - section: loki + key: org_id + loki_default_tags: + description: "Tags (key:value) to set for each log line" + env: + - name: LOKI_DEFAULT_TAGS + ini: + - section: loki + key: default_tags + type: list result_format: - name: Result format default: json description: Format used in results (will be set to json) pretty_results: - name: Print results pretty default: False description: Whether to print results pretty (will be set to false) + enabled_dumps: + description: | + Dumps to enable. The values playbook, diff, play, task and runner are available. + This usually requires that max_line_size in Loki is set to a higher value than 256kb. + type: list + env: + - name: LOKI_ENABLED_DUMPS + ini: + - section: loki + key: enabled_dumps ''' @@ -37,28 +82,26 @@ class CallbackModule(CallbackBase): CALLBACK_NAME = 'loki' ALL_METRICS = ["changed", "custom", "dark", "failures", "ignored", "ok", "processed", "rescued", "skipped"] - def __init__(self): - super().__init__() - - if "LOKI_URL" not in os.environ: - raise "LOKI_URL environment variable not specified." - + def __init__(self, display=None, options=None): + super().__init__(display, options) + self.set_options() auth = () - if "LOKI_USERNAME" in os.environ and "LOKI_PASSWORD" in os.environ: - auth = (os.environ["LOKI_USERNAME"], os.environ["LOKI_PASSWORD"]) + + if self.get_option("loki_username") and self.get_option("loki_password"): + auth = (self.get_option("loki_username"), self.get_option("loki_password")) headers = {} - if "LOKI_ORG_ID" in os.environ: - headers["X-Scope-OrgID"] = os.environ["LOKI_ORG_ID"] + if self.get_option("loki_org_id"): + headers["X-Scope-OrgID"] = self.get_option("loki_org_id") tags = {} - if "LOKI_DEFAULT_TAGS" in os.environ: - for tagvalue in os.environ["LOKI_DEFAULT_TAGS"].split(","): + if self.get_option("loki_default_tags"): + for tagvalue in self.get_option("loki_default_tags"): (tag, value) = tagvalue.split(":") tags[tag] = value handler = logging_loki.LokiHandler( - url=os.environ["LOKI_URL"], + url=self.get_option("loki_url"), tags=tags, auth=auth, headers=headers, @@ -77,6 +120,10 @@ def __init__(self): self.set_option("result_format", "json") self.set_option("pretty_results", False) + def _dump_enabled(self, dump): + return self.get_option("enabled_dumps") and dump in self.get_option("enabled_dumps") + + def v2_playbook_on_start(self, playbook): self.playbook = os.path.join(playbook._basedir, playbook._file_name) self.run_timestamp = datetime.datetime.now().isoformat() @@ -84,10 +131,11 @@ def v2_playbook_on_start(self, playbook): "Starting playbook %s" % self.playbook, extra={"tags": {"playbook": self.playbook, "run_timestamp": self.run_timestamp}} ) - self.logger.debug( - jsonpickle.encode(playbook.__dict__), - extra={"tags": {"playbook": self.playbook, "run_timestamp": self.run_timestamp, "dump": "playbook"}} - ) + if self._dump_enabled("playbook"): + self.logger.debug( + jsonpickle.encode(playbook.__dict__), + extra={"tags": {"playbook": self.playbook, "run_timestamp": self.run_timestamp, "dump": "playbook"}} + ) def v2_playbook_on_play_start(self, play): self.current_play = play.name @@ -95,17 +143,18 @@ def v2_playbook_on_play_start(self, play): "Starting play %s" % play.name, extra={"tags": {"playbook": self.playbook, "run_timestamp": self.run_timestamp, "play": self.current_play}} ) - self.logger.debug( - jsonpickle.encode(play.__dict__), - extra={ - "tags": { - "playbook": self.playbook, - "run_timestamp": self.run_timestamp, - "play": self.current_play, - "dump": "play" + if self._dump_enabled("play"): + self.logger.debug( + jsonpickle.encode(play.__dict__), + extra={ + "tags": { + "playbook": self.playbook, + "run_timestamp": self.run_timestamp, + "play": self.current_play, + "dump": "play" + } } - } - ) + ) def v2_playbook_on_task_start(self, task, is_conditional): self.current_task = task.name @@ -120,18 +169,19 @@ def v2_playbook_on_task_start(self, task, is_conditional): } } ) - self.logger.debug( - jsonpickle.encode(task.__dict__), - extra={ - "tags": { - "playbook": self.playbook, - "run_timestamp": self.run_timestamp, - "play": self.current_play, - "task": self.current_task, - "dump": "task" + if self._dump_enabled("task"): + self.logger.debug( + jsonpickle.encode(task.__dict__), + extra={ + "tags": { + "playbook": self.playbook, + "run_timestamp": self.run_timestamp, + "play": self.current_play, + "task": self.current_task, + "dump": "task" + } } - } - ) + ) def v2_runner_on_ok(self, result): self.logger.debug( @@ -145,18 +195,19 @@ def v2_runner_on_ok(self, result): } } ) - self.logger.debug( - self._dump_results(result._result), - extra={ - "tags": { - "playbook": self.playbook, - "run_timestamp": self.run_timestamp, - "play": self.current_play, - "task": self.current_task, - "dump": "runner" + if self._dump_enabled("runner"): + self.logger.debug( + self._dump_results(result._result), + extra={ + "tags": { + "playbook": self.playbook, + "run_timestamp": self.run_timestamp, + "play": self.current_play, + "task": self.current_task, + "dump": "runner" + } } - } - ) + ) def v2_runner_on_failed(self, result, ignore_errors=False): level = logging.WARNING if ignore_errors else logging.ERROR @@ -176,18 +227,19 @@ def v2_runner_on_failed(self, result, ignore_errors=False): } } ) - self.logger.debug( - self._dump_results(result._result), - extra={ - "tags": { - "playbook": self.playbook, - "run_timestamp": self.run_timestamp, - "play": self.current_play, - "task": self.current_task, - "dump": "runner" + if self._dump_enabled("runner"): + self.logger.debug( + self._dump_results(result._result), + extra={ + "tags": { + "playbook": self.playbook, + "run_timestamp": self.run_timestamp, + "play": self.current_play, + "task": self.current_task, + "dump": "runner" + } } - } - ) + ) def v2_runner_on_skipped(self, result): self.logger.info( @@ -201,18 +253,19 @@ def v2_runner_on_skipped(self, result): } } ) - self.logger.debug( - self._dump_results(result._result), - extra={ - "tags": { - "playbook": self.playbook, - "run_timestamp": self.run_timestamp, - "play": self.current_play, - "task": self.current_task, - "dump": "runner" + if self._dump_enabled("runner"): + self.logger.debug( + self._dump_results(result._result), + extra={ + "tags": { + "playbook": self.playbook, + "run_timestamp": self.run_timestamp, + "play": self.current_play, + "task": self.current_task, + "dump": "runner" + } } - } - ) + ) def runner_on_unreachable(self, host, result): self.logger.error( @@ -226,18 +279,19 @@ def runner_on_unreachable(self, host, result): } } ) - self.logger.debug( - self._dump_results(result), - extra={ - "tags": { - "playbook": self.playbook, - "run_timestamp": self.run_timestamp, - "play": self.current_play, - "task": self.current_task, - "dump": "runner" + if self._dump_enabled("runner"): + self.logger.debug( + self._dump_results(result), + extra={ + "tags": { + "playbook": self.playbook, + "run_timestamp": self.run_timestamp, + "play": self.current_play, + "task": self.current_task, + "dump": "runner" + } } - } - ) + ) def v2_playbook_on_no_hosts_matched(self): self.logger.error( @@ -263,19 +317,20 @@ def v2_on_file_diff(self, result): } } ) - for diff in diff_list: - self.logger.debug( - self._serialize_diff(diff), - extra={ - "tags": { - "playbook": self.playbook, - "run_timestamp": self.run_timestamp, - "play": self.current_play, - "task": self.current_task, - "dump": "diff" + if self._dump_enabled("diff"): + for diff in diff_list: + self.logger.debug( + self._serialize_diff(diff), + extra={ + "tags": { + "playbook": self.playbook, + "run_timestamp": self.run_timestamp, + "play": self.current_play, + "task": self.current_task, + "dump": "diff" + } } - } - ) + ) def v2_playbook_on_stats(self, stats): summarize_metrics = {} diff --git a/test/ansible.cfg b/test/ansible.cfg new file mode 100644 index 0000000..941cc1e --- /dev/null +++ b/test/ansible.cfg @@ -0,0 +1,6 @@ +[defaults] +callback_plugins=../ + +[loki] +url=http://localhost:3100/loki/api/v1/push +default_tags=run:test \ No newline at end of file diff --git a/test/default/inventory.yaml b/test/default/inventory.yaml new file mode 100644 index 0000000..4cc04d8 --- /dev/null +++ b/test/default/inventory.yaml @@ -0,0 +1,4 @@ +unreachable: + hosts: + unreachable_host: + ansible_host: 1.1.1.1 \ No newline at end of file diff --git a/test/default/playbook.yaml b/test/default/playbook.yaml new file mode 100644 index 0000000..bdcd774 --- /dev/null +++ b/test/default/playbook.yaml @@ -0,0 +1,48 @@ +- name: Test1 + hosts: 127.0.0.1 + connection: local + gather_facts: no + tasks: + - name: Call github + uri: + url: 'https://github.com' + +- name: Testdiff + hosts: 127.0.0.1 + connection: local + gather_facts: no + tasks: + - name: Create temp file + tempfile: {} + register: tempfile + - name: Write tempfile + copy: + dest: "{{ tempfile.path }}" + content: "test" + +- name: TestFail + hosts: 127.0.0.1 + connection: local + gather_facts: no + tasks: + - name: Produce failure + command: exit 1 + ignore_errors: yes + +- name: Testskipped + hosts: 127.0.0.1 + connection: local + gather_facts: no + tasks: + - name: Skip it + command: exit 1 + when: impossible is defined + +- name: Testunreachable + hosts: unreachable + gather_facts: no + ignore_errors: yes + tasks: + - name: Call github + uri: + url: 'https://github.com' diff --git a/test/playbook.yaml b/test/playbook.yaml new file mode 100644 index 0000000..d56fe9b --- /dev/null +++ b/test/playbook.yaml @@ -0,0 +1,53 @@ +- hosts: 127.0.0.1 + gather_facts: false + connection: local + name: Start Loki + tasks: + - name: Start Loki container + docker_container: + image: "grafana/loki:3.0.1" + name: "ansible-loki-callback-test" + auto_remove: true + published_ports: + - "3100:3100" + state: started + register: loki_container + - name: Wait for Loki to be ready + uri: + url: "http://localhost:3100/ready" + register: _result + until: _result.status == 200 + retries: 100 + delay: 5 + +- import_playbook: "default/playbook.yaml" + +- hosts: 127.0.0.1 + gather_facts: false + connection: local + name: "Checking results" + tasks: + - name: "Fetching number of recorded logs" + uri: + url: http://localhost:3100/loki/api/v1/query_range?query={{ '{run="test"}' | urlencode }} + body_format: json + register: logs + - name: tmp1 + ansible.builtin.debug: + var: expected_records + - name: tmp2 + ansible.builtin.debug: + var: logs.json.data.result | length + - fail: + msg: "Invalid number of records" + when: logs.json.data.result | length != expected_records | int + +- hosts: 127.0.0.1 + gather_facts: false + connection: local + name: Stop Loki + tasks: + - name: Stop Loki container + docker_container: + name: "ansible-loki-callback-test" + state: stopped From 2c37c3b1ab47596d23460c090366c87d3d0d16d9 Mon Sep 17 00:00:00 2001 From: Dennis Ploeger Date: Fri, 16 Aug 2024 13:54:28 +0200 Subject: [PATCH 2/5] fix: Fix unreachable test --- .github/workflows/test.yml | 4 ++-- test/default/playbook.yaml | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 72736a2..5752be6 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -30,5 +30,5 @@ jobs: - name: Run test run: | cd test - python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=20 -vvv - LOKI_ENABLED_DUMPS=play python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=26 -vvv \ No newline at end of file + python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=21 -vvv + LOKI_ENABLED_DUMPS=play python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=27 -vvv \ No newline at end of file diff --git a/test/default/playbook.yaml b/test/default/playbook.yaml index bdcd774..5411f73 100644 --- a/test/default/playbook.yaml +++ b/test/default/playbook.yaml @@ -41,7 +41,7 @@ - name: Testunreachable hosts: unreachable gather_facts: no - ignore_errors: yes + ignore_unreachable: yes tasks: - name: Call github uri: From 311a6c1a6a1fccad7307139e1d30a371de46d0a7 Mon Sep 17 00:00:00 2001 From: Dennis Ploeger Date: Fri, 16 Aug 2024 13:57:06 +0200 Subject: [PATCH 3/5] chore: Optimized test workflow --- .github/workflows/test.yml | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 5752be6..6790ba3 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -27,8 +27,11 @@ jobs: run: | python -m pip install --upgrade pip pip install -r requirements.txt -r requirements-dev.txt - - name: Run test - run: | - cd test - python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=21 -vvv - LOKI_ENABLED_DUMPS=play python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=27 -vvv \ No newline at end of file + - name: Run default test + working-directory: test + run: python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=21 -vvv + - name: Run dump configuration test + working-directory: test + env: + LOKI_ENABLED_DUMPS: play + run: python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=21 -vvv From 4c3900cd7f8b75eaf82ee1a2400d36c0041b7bbe Mon Sep 17 00:00:00 2001 From: Dennis Ploeger Date: Fri, 16 Aug 2024 14:36:16 +0200 Subject: [PATCH 4/5] chore: Fixed test workflow --- .github/workflows/test.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 6790ba3..6268eff 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -34,4 +34,4 @@ jobs: working-directory: test env: LOKI_ENABLED_DUMPS: play - run: python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=21 -vvv + run: python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=27 -vvv From af423e6706d7173c79f3caac36b71ff14401eb62 Mon Sep 17 00:00:00 2001 From: Dennis Ploeger Date: Mon, 19 Aug 2024 17:21:10 +0200 Subject: [PATCH 5/5] chore: Optimized runs of test suite --- .github/workflows/test.yml | 9 ++----- test/ansible.cfg | 3 --- test/playbook.yaml | 53 -------------------------------------- test/playbook_check.yaml | 19 ++++++++++++++ test/playbook_cleanup.yaml | 9 +++++++ test/playbook_prepare.yaml | 21 +++++++++++++++ test/test.sh | 24 +++++++++++++++++ 7 files changed, 75 insertions(+), 63 deletions(-) delete mode 100644 test/playbook.yaml create mode 100644 test/playbook_check.yaml create mode 100644 test/playbook_cleanup.yaml create mode 100644 test/playbook_prepare.yaml create mode 100644 test/test.sh diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 6268eff..8ea0aba 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -27,11 +27,6 @@ jobs: run: | python -m pip install --upgrade pip pip install -r requirements.txt -r requirements-dev.txt - - name: Run default test + - name: Run testsuite working-directory: test - run: python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=21 -vvv - - name: Run dump configuration test - working-directory: test - env: - LOKI_ENABLED_DUMPS: play - run: python -m ansible.cli.playbook playbook.yaml -i default/inventory.yaml -e expected_records=27 -vvv + run: /usr/bin/env bash test.sh diff --git a/test/ansible.cfg b/test/ansible.cfg index 941cc1e..2d0614e 100644 --- a/test/ansible.cfg +++ b/test/ansible.cfg @@ -1,6 +1,3 @@ -[defaults] -callback_plugins=../ - [loki] url=http://localhost:3100/loki/api/v1/push default_tags=run:test \ No newline at end of file diff --git a/test/playbook.yaml b/test/playbook.yaml deleted file mode 100644 index d56fe9b..0000000 --- a/test/playbook.yaml +++ /dev/null @@ -1,53 +0,0 @@ -- hosts: 127.0.0.1 - gather_facts: false - connection: local - name: Start Loki - tasks: - - name: Start Loki container - docker_container: - image: "grafana/loki:3.0.1" - name: "ansible-loki-callback-test" - auto_remove: true - published_ports: - - "3100:3100" - state: started - register: loki_container - - name: Wait for Loki to be ready - uri: - url: "http://localhost:3100/ready" - register: _result - until: _result.status == 200 - retries: 100 - delay: 5 - -- import_playbook: "default/playbook.yaml" - -- hosts: 127.0.0.1 - gather_facts: false - connection: local - name: "Checking results" - tasks: - - name: "Fetching number of recorded logs" - uri: - url: http://localhost:3100/loki/api/v1/query_range?query={{ '{run="test"}' | urlencode }} - body_format: json - register: logs - - name: tmp1 - ansible.builtin.debug: - var: expected_records - - name: tmp2 - ansible.builtin.debug: - var: logs.json.data.result | length - - fail: - msg: "Invalid number of records" - when: logs.json.data.result | length != expected_records | int - -- hosts: 127.0.0.1 - gather_facts: false - connection: local - name: Stop Loki - tasks: - - name: Stop Loki container - docker_container: - name: "ansible-loki-callback-test" - state: stopped diff --git a/test/playbook_check.yaml b/test/playbook_check.yaml new file mode 100644 index 0000000..b9abf1c --- /dev/null +++ b/test/playbook_check.yaml @@ -0,0 +1,19 @@ +- hosts: 127.0.0.1 + gather_facts: false + connection: local + name: "Checking results" + tasks: + - name: "Fetching number of recorded logs" + uri: + url: http://localhost:3100/loki/api/v1/query_range?query={{ '{run="test"}' | urlencode }} + body_format: json + register: logs + - name: tmp1 + ansible.builtin.debug: + var: expected_records + - name: tmp2 + ansible.builtin.debug: + var: logs.json.data.result | length + - fail: + msg: "Invalid number of records" + when: logs.json.data.result | length != expected_records | int diff --git a/test/playbook_cleanup.yaml b/test/playbook_cleanup.yaml new file mode 100644 index 0000000..0f80700 --- /dev/null +++ b/test/playbook_cleanup.yaml @@ -0,0 +1,9 @@ +- hosts: 127.0.0.1 + gather_facts: false + connection: local + name: Stop Loki + tasks: + - name: Stop Loki container + docker_container: + name: "ansible-loki-callback-test" + state: stopped diff --git a/test/playbook_prepare.yaml b/test/playbook_prepare.yaml new file mode 100644 index 0000000..034cf56 --- /dev/null +++ b/test/playbook_prepare.yaml @@ -0,0 +1,21 @@ +- hosts: 127.0.0.1 + gather_facts: false + connection: local + name: Start Loki + tasks: + - name: Start Loki container + docker_container: + image: "grafana/loki:3.0.1" + name: "ansible-loki-callback-test" + auto_remove: true + published_ports: + - "3100:3100" + state: started + register: loki_container + - name: Wait for Loki to be ready + uri: + url: "http://localhost:3100/ready" + register: _result + until: _result.status == 200 + retries: 100 + delay: 5 diff --git a/test/test.sh b/test/test.sh new file mode 100644 index 0000000..cd11047 --- /dev/null +++ b/test/test.sh @@ -0,0 +1,24 @@ +#!/usr/bin/env bash + +set -euo pipefail + +function run() { + if ! LOG=$("$@" 2>&1); then + STATUS=$? + echo "$LOG" + exit $STATUS + fi +} + +echo "Running default test" +run python -m ansible.cli.playbook playbook_prepare.yaml +ANSIBLE_CALLBACK_PLUGINS=.. run python -m ansible.cli.playbook default/playbook.yaml -i default/inventory.yaml -vvv +run python -m ansible.cli.playbook playbook_check.yaml -e expected_records=20 -vvv +run python -m ansible.cli.playbook playbook_cleanup.yaml + +# Check with dumps +echo "Running dump test" +run python -m ansible.cli.playbook playbook_prepare.yaml +LOKI_ENABLED_DUMPS=task ANSIBLE_CALLBACK_PLUGINS=.. run python -m ansible.cli.playbook default/playbook.yaml -i default/inventory.yaml -vvv +run python -m ansible.cli.playbook playbook_check.yaml -e expected_records=26 -vvv +run python -m ansible.cli.playbook playbook_cleanup.yaml \ No newline at end of file