Skip to content
Open
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
156 changes: 156 additions & 0 deletions tests/integration/test_facts.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,156 @@
# SPDX-License-Identifier: Apache-2.0

"""Integration tests for ``osism.utils.check_ansible_facts()``.

The function scans Redis for ``ansible_facts*`` keys with a cursor-based
``SCAN`` loop and reads ``ansible_date_time.epoch`` from each JSON value to
decide whether the cached facts are stale, reporting the outcome through
loguru. The unit tests cover the same scenarios against a ``MagicMock``
client; running them against a live Redis exercises what the mocks stand in
for: the cursor loop, keys and values arriving as ``bytes``, and JSON that

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The cursor loop is listed first among the things a live Redis exercises, and it is the one path this file does not reach. check_ansible_facts() calls r.scan(cursor, match="ansible_facts*", count=100) (osism/utils/__init__.py:617), and the largest scenario here seeds two keys. Measured against redis:7-alpine on an empty database:

keys seeded first cursor loop iterations
2 0 1
50 0 1
64 0 1
100 127 2
200 193 2
300 138 3

So on the container the job provides, the while True body runs exactly once and keys.extend(batch) never accumulates. Worth noting the threshold is well above "seed a few more": 64 keys still completes in one call, because SCAN walks hash buckets rather than matching keys and count=100 covers the whole table until it grows past that.

The consequence is concrete. Refactoring the loop to a single call — cursor, keys = r.scan(0, match="ansible_facts*", count=100), a plausible simplification — leaves this file entirely green: 20 of 20 runs pass at two keys. A 200-host version fails 20 of 20, reporting only 100–102 of the 200 stale hosts. That is the regression the docstring implies is covered, and the mocked pagination test at tests/unit/utils/test_init_task_output.py:639-658 is what currently catches it.

Either exercise it or drop "the cursor loop" from the list; the bytes and round-tripped-JSON claims are real and worth keeping. I would exercise it, for a reason beyond the refactor above: Redis documents that SCAN may return the same element more than once while the keyspace rehashes, and osism/utils/__init__.py:614-620 extends a flat list with no dedup — which would inflate the count at :673-676 and print a host's warning twice. A mocked test that hard-codes distinct keys per batch encodes exactly-once semantics that live SCAN does not promise, so that class of defect is only reachable here.

If you exercise it, a behavioural assertion beats counting scan() calls — a call-count spy means wrapping the live client, which reintroduces the mock this file exists to escape:

def test_stale_facts_across_scan_batches(seed_facts, loguru_logs):
    hosts = [_host() for _ in range(200)]
    for host in hosts:
        seed_facts(host, _facts(time.time() - 9999))

    # Precondition: a single SCAN cannot cover this keyspace, so the loop in
    # check_ansible_facts() must iterate. COUNT is documented as a hint, so this
    # fails loudly if a future Redis makes 200 keys insufficient rather than
    # silently passing without testing pagination.
    cursor, _ = utils.redis.scan(0, match="ansible_facts*", count=100)
    assert cursor != 0

    utils.check_ansible_facts(max_age=MAX_AGE)

    assert _messages(loguru_logs, "WARNING", f"stale for {len(hosts)} host(s)")
    for host in hosts:
        assert _messages(loguru_logs, "WARNING", f"Host '{host}': facts are")

Asserting every host is what proves the batches accumulated. The commit message carries the same claim about the SCAN loop and would want the same correction.

round-tripped through a Redis server. The suite is skipped automatically when
Redis is not reachable (see ``conftest.py``).
"""

import json
import time
import uuid

import pytest

from osism import utils

pytestmark = pytest.mark.integration

# Passed explicitly to every call: the ``settings.FACTS_MAX_AGE`` default is 12
# hours, which would tie the stale case to the environment.
MAX_AGE = 300


@pytest.fixture
def seed_facts():
"""Seed ``ansible_facts<host>`` keys and remove them after the test."""

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This fixture is byte-for-byte identical to tests/integration/test_api_facts.py:38-51, docstring included. Both build f"ansible_facts{host}" — the key format the two suites exist to pin, one for check_ansible_facts(), one for the inventory-facts endpoints — so changing that format and updating only one copy leaves the other seeding the old layout and still passing.

Nothing to change in this PR. In a commit of its own afterwards: move seed_facts into the existing tests/integration/conftest.py and delete both copies, and add a unique-host fixture there to replace _host() here and the six inline f"itest-{uuid.uuid4()}" in test_api_facts.py. That one wants to be a factory rather than a plain string fixture, since test_stale_facts_report_the_stale_host_only needs two hosts in one test.

keys = []

def _seed(host, value):
key = f"ansible_facts{host}"
utils.redis.set(key, value)
keys.append(key)

yield _seed

for key in keys:
utils.redis.delete(key)


def _host():
"""Return a hostname unique to one test.

The ``itest-`` prefix keeps it clear of ``LOCAL_FACT_HOSTS``, whose facts
``check_ansible_facts()`` skips outright.
"""
return f"itest-{uuid.uuid4()}"


def _facts(epoch):
"""Return a facts blob carrying ``epoch``.

Ansible stores the epoch as a string, and ``check_ansible_facts()`` casts
it with ``float()``, so the string form is what the test seeds.
"""
return json.dumps({"ansible_date_time": {"epoch": str(int(epoch))}})


def _messages(records, level, needle):
"""Return the captured messages at ``level`` that contain ``needle``."""
return [
record["message"]
for record in records
if record["level"] == level and needle in record["message"]
]


def test_no_facts_warns_about_empty_cache(loguru_logs):
"""An empty facts cache is reported as such.

``check_ansible_facts()`` scans the whole database, so a Redis holding
real facts cannot produce this case. Skip there rather than deleting data
that does not belong to the suite; the CI container starts empty.
"""
leftover = sorted(
key.decode() for key in utils.redis.scan_iter(match="ansible_facts*")
)
if leftover:
pytest.skip(f"Redis already holds ansible_facts keys: {leftover}")

utils.check_ansible_facts(max_age=MAX_AGE)

assert _messages(loguru_logs, "WARNING", "No Ansible facts found in Redis cache")


def test_fresh_facts_produce_no_warning(seed_facts, loguru_logs):
"""A host whose facts are current is not reported."""
host = _host()
seed_facts(host, _facts(time.time()))

utils.check_ansible_facts(max_age=MAX_AGE)

assert not _messages(loguru_logs, "WARNING", host)


def test_stale_facts_report_the_stale_host_only(seed_facts, loguru_logs):
"""Facts older than ``max_age`` are reported, fresh ones are not."""
stale_host = _host()
fresh_host = _host()
seed_facts(stale_host, _facts(time.time() - 9999))
seed_facts(fresh_host, _facts(time.time()))

utils.check_ansible_facts(max_age=MAX_AGE)

stale_messages = _messages(
loguru_logs, "WARNING", f"Host '{stale_host}': facts are"
)
assert stale_messages
assert all("seconds old" in message for message in stale_messages)
assert _messages(loguru_logs, "WARNING", "Run 'osism sync facts' to update facts.")
assert not _messages(loguru_logs, "WARNING", fresh_host)


def test_facts_without_epoch_are_skipped(seed_facts, loguru_logs):
"""Facts lacking ``ansible_date_time.epoch`` are skipped, not reported."""
host = _host()
seed_facts(host, json.dumps({"ansible_hostname": "node-1"}))

utils.check_ansible_facts(max_age=MAX_AGE)

assert _messages(
loguru_logs, "DEBUG", f"Host '{host}': facts missing ansible_date_time.epoch"
)
assert not _messages(loguru_logs, "WARNING", host)


def test_malformed_json_is_skipped(seed_facts, loguru_logs):
"""A value that is not JSON is skipped without failing the check.

The debug call uses printf-style placeholders that loguru's ``str.format``

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This docstring is accurate about the behaviour, but it is worth fixing rather than documenting. loguru formats with str.format, so the template at osism/utils/__init__.py:664-669 discards key and truncated_value entirely — the recorded message is the literal Skipping malformed ansible_facts entry for key %r: %r. exc_info=True is inert too: loguru has no such kwarg, so it is swallowed as a format argument and record["exception"] stays None. Verified against loguru 0.7.3. An operator hitting corrupt cached facts gets a message naming neither the host, nor the payload, nor the parse error — on the one path where all three matter.

That also makes line 144 weaker than it reads. With no host in the message, any malformed ansible_facts* entry in a shared Redis satisfies it: this test's own key could never be processed and the assertion would still pass. It is also the exception to the commit message's claim that "every assertion is scoped to a seeded hostname or to a message unique to its scenario" — that sentence wants qualifying either way.

One line in osism/utils/__init__.py:

logger.opt(exception=True).debug(
    f"Skipping malformed ansible_facts entry for key {key!r}: {truncated_value!r}"
)

then this paragraph goes away and line 144 becomes assert _messages(loguru_logs, "DEBUG", host). Confirmed that the fix produces Skipping malformed ansible_facts entry for key b'ansible_factsitest-…': b'{ not valid json' with a JSONDecodeError attached.

If you would rather keep the diff tests-only, that splits cleanly — with the fix applied, this file and the affected unit modules stay green (12 and 77 tests), because every assertion is a substring match on a prefix the interpolated message retains. But please drop this paragraph in this PR regardless: nothing will turn red to signal that prose describing placeholders is stale once they are gone. The same pattern exists at osism/commands/console.py:124 and would want the same treatment.

leaves in place, so the recorded message is the literal template. Match on
its prefix rather than on interpolated values.
"""
host = _host()
seed_facts(host, "{ not valid json")

utils.check_ansible_facts(max_age=MAX_AGE)

assert _messages(loguru_logs, "DEBUG", "Skipping malformed ansible_facts entry")
assert not _messages(loguru_logs, "WARNING", host)


def test_empty_value_is_skipped(seed_facts, loguru_logs):
"""An empty value is skipped silently."""
host = _host()
seed_facts(host, "")

utils.check_ansible_facts(max_age=MAX_AGE)

assert not _messages(loguru_logs, "WARNING", host)
assert not _messages(loguru_logs, "DEBUG", host)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Both assertions here are absence-only and the seeded input produces no log output at all, so nothing distinguishes "skipped the empty entry and kept scanning" from "skipped it and stopped". Line 156 in particular has almost no failure mode: the only reachable DEBUG message containing a hostname is the missing-epoch one at osism/utils/__init__.py:653-655, which an empty value never reaches, so even removing if not data: continue — making json.loads("") raise — leaves this green.

Measured over 200 trials per case, replacing that continue with an early exit:

test continuereturn continuebreak
as written (one empty key) 0/200 caught 0/200 caught
co-seeding 1 stale host 200/200 78/200
co-seeding 5 stale hosts 200/200 173/200

Co-seeding a stale host and asserting it is still reported costs two lines and catches the early-return case deterministically — order-independently, because stale hosts are reported after the loop, so an early return skips the summary regardless of which key SCAN returns first. Five stale hosts also covers most of the break case. The correct implementation passed 200/200 in every configuration, so there is no flakiness cost.