diff --git a/lib/charms/loki_k8s/v0/charm_logging.py b/lib/charms/loki_k8s/v0/charm_logging.py new file mode 100644 index 000000000..cea0393d7 --- /dev/null +++ b/lib/charms/loki_k8s/v0/charm_logging.py @@ -0,0 +1,357 @@ +#!/usr/bin/env python3 +# Copyright 2022 Canonical Ltd. +# See LICENSE file for licensing details. + +"""This charm library contains utilities to automatically forward your charm logs to a loki-push-api endpoint. + +(yes! charm code, not workload code!) + +If your charm isn't already related to Loki using any of the +consumers/forwarders from the ``loki_push_api`` library, you need to: + + charmcraft fetch-lib charms.loki_k8s.v1.loki_push_api + +and add the logging consumer that matches your use case. +See https://charmhub.io/loki-k8s/libraries/loki_push_apihttps://charmhub.io/loki-k8s/libraries/loki_push_api +for more information. + +Once your charm is related to, for example, COS' Loki charm (or a Grafana Agent), +you will be able to inspect in real time from the Grafana dashboard the logs emitted by your charm. + +## Labels + +The library will inject the following labels into the records sent to Loki: +- ``model``: name of the juju model this charm is deployed to +- ``model_uuid``: uuid of the model +- ``application``: juju application name (such as 'mycharm') +- ``unit``: unit name (such as 'mycharm/0') +- ``charm_name``: name of the charm (whatever is in metadata.yaml) under 'name'. +- ``juju_hook_name``: name of the juju event being processed +` ``service_name``: name of the service this charm represents. + Defaults to app name, but can be configured by the user. + +## Usage + +To start using this library, you need to do two things: +1) decorate your charm class with + + @log_charm(loki_push_api_endpoint="my_logging_endpoints") + +2) add to your charm a "my_logging_endpoint" (you can name this attribute whatever you like) **property** +that returns an http/https endpoint url. If you are using the `LokiPushApiConsumer` as +`self.logging = LokiPushApiConsumer(self, ...)`, the implementation could be: + + @property + def my_logging_endpoints(self) -> List[str]: + '''Loki push API endpoints for charm logging.''' + # this will return an empty list if there is no relation or there is no data yet in the relation + return ["http://loki-0.loki.svc.cluster.local:3100"] + +The ``log_charm`` decorator will take these endpoints and set up the root logger (as in python's +logging module root logger) to forward all logs to these loki endpoints. + +## TLS support +If your charm integrates with a tls provider which is also trusted by the logs receiver, you can +configure TLS by passing a ``server_cert`` parameter to the decorator. + +If you're not using the same CA as the loki-push-api endpoint you are sending logs to, +you'll need to implement a cert-transfer relation to obtain the CA certificate from the same +CA that Loki is using. + +``` +@log_charm(loki_push_api_endpoint="my_logging_endpoint", server_cert="my_server_cert") +class MyCharm(...): + ... + + @property + def my_server_cert(self) -> Optional[str]: + '''Absolute path to a server crt if TLS is enabled.''' + if self.tls_is_enabled(): + return "/path/to/my/server_cert.crt" +``` +""" +import functools +import logging +import os +from contextlib import contextmanager +from pathlib import Path +from typing import ( + Callable, + Optional, + Sequence, + Type, + TypeVar, + Union, +) + +from cosl import JujuTopology +from cosl.loki_logger import LokiHandler # pyright:ignore[reportMissingImports] +from ops.charm import CharmBase +from ops.framework import Framework + +# The unique Charmhub library identifier, never change it +LIBID = "52ee6051f4e54aedaa60aa04134d1a6d" + +# Increment this major API version when introducing breaking changes +LIBAPI = 0 + +# Increment this PATCH version before using `charmcraft publish-lib` or reset +# to 0 if you are raising the major API version +LIBPATCH = 1 + +PYDEPS = ["cosl"] + +logger = logging.getLogger("charm_logging") +_EndpointGetterType = Union[Callable[[CharmBase], Optional[Sequence[str]]], property] +_CertGetterType = Union[Callable[[CharmBase], Optional[str]], property] +CHARM_LOGGING_ENABLED = "CHARM_LOGGING_ENABLED" + + +def is_enabled() -> bool: + """Whether charm logging is enabled. + + We assume it is enabled, unless the envvar CHARM_LOGGING_ENABLED is set to `0` + (or anything except `1`). + """ + return os.getenv(CHARM_LOGGING_ENABLED, "1") == "1" + + +class CharmLoggingError(Exception): + """Base class for all exceptions raised by this module.""" + + +class InvalidEndpointError(CharmLoggingError): + """Raised if an endpoint is invalid.""" + + +class InvalidEndpointsError(CharmLoggingError): + """Raised if an endpoint is invalid.""" + + +@contextmanager +def charm_logging_disabled(): + """Contextmanager to temporarily disable charm logging. + + For usage in tests. + """ + previous = os.getenv(CHARM_LOGGING_ENABLED) + os.environ[CHARM_LOGGING_ENABLED] = "0" + + yield + + if previous is None: + os.environ.pop(CHARM_LOGGING_ENABLED) + else: + os.environ[CHARM_LOGGING_ENABLED] = previous + + +_C = TypeVar("_C", bound=Type[CharmBase]) +_T = TypeVar("_T", bound=type) +_F = TypeVar("_F", bound=Type[Callable]) + + +def _get_logging_endpoints( + logging_endpoints_getter: _EndpointGetterType, self: CharmBase, charm: Type[CharmBase] +): + logging_endpoints: Optional[Sequence[str]] + + if isinstance(logging_endpoints_getter, property): + logging_endpoints = logging_endpoints_getter.__get__(self) + else: # method or callable + logging_endpoints = logging_endpoints_getter(self) + + if logging_endpoints is None: + logger.debug( + f"Charm logging disabled. {charm.__name__}.{logging_endpoints_getter} returned None." + ) + return None + + errors = [] + sanitized_logging_endponts = [] + if isinstance(logging_endpoints, str): + errors.append("invalid return value: expected Iterable[str], got str") + else: + for endpoint in logging_endpoints: + if isinstance(endpoint, str): + sanitized_logging_endponts.append(endpoint) + else: + errors.append(f"invalid endpoint: expected string, got {endpoint!r}") + + if errors: + raise InvalidEndpointsError( + f"{charm}.{logging_endpoints_getter} should return an iterable of Loki push-api " + "(-compatible) endpoints (strings); " + f"ERRORS: {errors}" + ) + + return sanitized_logging_endponts + + +def _get_server_cert( + server_cert_getter: _CertGetterType, self: CharmBase, charm: Type[CharmBase] +) -> Optional[str]: + if isinstance(server_cert_getter, property): + server_cert = server_cert_getter.__get__(self) + else: # method or callable + server_cert = server_cert_getter(self) + + # we're assuming that the ca cert that signed this unit is the same that has signed loki's + if server_cert is None: + logger.debug(f"{charm.__name__}.{server_cert_getter} returned None.") + logger.warning( + "Charm logs are being sent over insecure http because a ca cert is " + "not provided to the charm_logging module." + ) + return None + + if not isinstance(server_cert, str) and not isinstance(server_cert, Path): + raise ValueError( + f"{charm}.{server_cert_getter} should return a valid path to a tls cert file (string | Path)); " + f"got a {type(server_cert)!r} instead." + ) + + sc_path = Path(server_cert).absolute() + if not sc_path.exists(): + raise RuntimeError( + f"{charm}.{server_cert_getter} returned bad path {server_cert!r}: " f"file not found." + ) + + return str(sc_path) + + +def _setup_root_logger_initializer( + charm: Type[CharmBase], + logging_endpoints_getter: _EndpointGetterType, + server_cert_getter: Optional[_CertGetterType], + service_name: Optional[str] = None, +): + """Patch the charm's initializer and inject a call to set up root logging.""" + original_init = charm.__init__ + + @functools.wraps(original_init) + def wrap_init(self: CharmBase, framework: Framework, *args, **kwargs): + original_init(self, framework, *args, **kwargs) + + if not is_enabled(): + logger.debug("Charm logging DISABLED by env: skipping root logger initialization") + return + + logging_endpoints = _get_logging_endpoints(logging_endpoints_getter, self, charm) + + if not logging_endpoints: + return + + juju_topology = JujuTopology.from_charm(self) + labels = { + **juju_topology.as_dict(), + "service_name": service_name or self.app.name, + "juju_hook_name": os.getenv("JUJU_HOOK_NAME", ""), + } + server_cert: Optional[Union[str, Path]] = ( + _get_server_cert(server_cert_getter, self, charm) if server_cert_getter else None + ) + + root_logger = logging.getLogger() + + for url in logging_endpoints: + handler = LokiHandler( + url=url, + labels=labels, + cert=str(server_cert) if server_cert else None, + ) + root_logger.addHandler(handler) + + logger.debug("Initialized LokiHandler and set up root logging for charm code.") + return + + charm.__init__ = wrap_init + + +def log_charm( + logging_endpoints: str, + server_cert: Optional[str] = None, + service_name: Optional[str] = None, +): + """Set up the root logger to forward any charm logs to one or more Loki push API endpoints. + + Usage: + >>> from charms.loki_k8s.v0.charm_logging import log_charm + >>> from charms.loki_k8s.v1.loki_push_api import LokiPushApiConsumer + >>> from ops import CharmBase + >>> + >>> @log_charm( + >>> logging_endpoints="loki_push_api_urls", + >>> ) + >>> class MyCharm(CharmBase): + >>> + >>> def __init__(self, framework: Framework): + >>> ... + >>> self.logging = LokiPushApiConsumer(self, ...) + >>> + >>> @property + >>> def loki_push_api_urls(self) -> Optional[List[str]]: + >>> return [endpoint['url'] for endpoint in self.logging.loki_endpoints] + >>> + :param server_cert: method or property on the charm type that returns an + optional absolute path to a tls certificate to be used when sending traces to a remote server. + If it returns None, an _insecure_ connection will be used. + :param logging_endpoints: name of a property on the charm type that returns a sequence + of (fully resolvable) Loki push API urls. If None, charm logging will be effectively disabled. + Else, the root logger will be set up to forward all logs to those endpoints. + :param service_name: service name tag to attach to all logs generated by this charm. + Defaults to the juju application name this charm is deployed under. + """ + + def _decorator(charm_type: Type[CharmBase]): + """Autoinstrument the wrapped charmbase type.""" + _autoinstrument( + charm_type, + logging_endpoints_getter=getattr(charm_type, logging_endpoints), + server_cert_getter=getattr(charm_type, server_cert) if server_cert else None, + service_name=service_name, + ) + return charm_type + + return _decorator + + +def _autoinstrument( + charm_type: Type[CharmBase], + logging_endpoints_getter: _EndpointGetterType, + server_cert_getter: Optional[_CertGetterType] = None, + service_name: Optional[str] = None, +) -> Type[CharmBase]: + """Set up logging on this charm class. + + Use this function to setup automatic log forwarding for all logs emitted throughout executions of + this charm. + + Usage: + + >>> from charms.loki_k8s.v0.charm_logging import _autoinstrument + >>> from ops.main import main + >>> _autoinstrument( + >>> MyCharm, + >>> logging_endpoints_getter=MyCharm.get_loki_endpoints, + >>> service_name="MyCharm", + >>> ) + >>> main(MyCharm) + + :param charm_type: the CharmBase subclass to autoinstrument. + :param server_cert_getter: method or property on the charm type that returns an + optional absolute path to a tls certificate to be used when sending traces to a remote server. + If it returns None, an _insecure_ connection will be used. + :param logging_endpoints_getter: name of a property on the charm type that returns a sequence + of (fully resolvable) Loki push API urls. If None, charm logging will be effectively disabled. + Else, the root logger will be set up to forward all logs to those endpoints. + :param service_name: service name tag to attach to all logs generated by this charm. + Defaults to the juju application name this charm is deployed under. + """ + logger.info(f"instrumenting {charm_type}") + _setup_root_logger_initializer( + charm_type, + logging_endpoints_getter, + server_cert_getter=server_cert_getter, + service_name=service_name, + ) + return charm_type diff --git a/pyproject.toml b/pyproject.toml index 6e4fd4ee0..8742f1e9b 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -37,3 +37,4 @@ pythonPlatform = "All" minversion = "6.0" log_cli_level = "INFO" asyncio_mode = "auto" +markers = ["setup", "work", "teardown"] \ No newline at end of file diff --git a/requirements.txt b/requirements.txt index cdbc96519..55f697c37 100644 --- a/requirements.txt +++ b/requirements.txt @@ -1,4 +1,4 @@ -cosl +cosl>=0.0.12 ops kubernetes requests @@ -12,3 +12,7 @@ lightkube-models # Cryptography # Deps: tls_certificates cryptography + +# deps: tracing, charm_tracing +pydantic +opentelemetry-exporter-otlp-proto-http==1.21.0 diff --git a/src/charm.py b/src/charm.py index 53e9a7926..8c4f35bbb 100755 --- a/src/charm.py +++ b/src/charm.py @@ -30,6 +30,7 @@ from charms.catalogue_k8s.v1.catalogue import CatalogueConsumer, CatalogueItem from charms.grafana_k8s.v0.grafana_dashboard import GrafanaDashboardProvider from charms.grafana_k8s.v0.grafana_source import GrafanaSourceProvider +from charms.loki_k8s.v0.charm_logging import log_charm from charms.loki_k8s.v0.loki_push_api import ( LokiPushApiAlertRulesChanged, LokiPushApiProvider, @@ -108,12 +109,15 @@ def to_status(tpl: Tuple[str, str]) -> StatusBase: MetricsEndpointProvider, ], ) +@log_charm(logging_endpoints="logging_endpoints", server_cert="server_ca_cert_path") class LokiOperatorCharm(CharmBase): """Charm the service.""" _stored = StoredState() _port = HTTP_LISTEN_PORT _name = "loki" + _loki_push_api_endpoint = "/loki/api/v1/push" + _loki_rules_endpoint = "/loki/api/v1/rules" _service_name = "loki" _ca_cert_path = "/usr/local/share/ca-certificates/cos-ca.crt" @@ -207,7 +211,7 @@ def __init__(self, *args): address=external_url.hostname or self.hostname, port=external_url.port or 443 if self._tls_ready else 80, scheme=external_url.scheme, - path=f"{external_url.path}/loki/api/v1/push", + path=f"{external_url.path}{self._loki_push_api_endpoint}", ) self.dashboard_provider = GrafanaDashboardProvider(self) @@ -380,6 +384,12 @@ def hostname(self) -> str: """Unit's hostname.""" return socket.getfqdn() + @property + def internal_url(self): + """Fqdn plus appropriate scheme and server port.""" + scheme = "https" if self.server_cert.server_cert else "http" + return f"{scheme}://{self.hostname}:{self._port}" + @property def _external_url(self) -> str: """Return the external hostname to be passed to ingress via the relation.""" @@ -393,8 +403,7 @@ def _external_url(self) -> str: # are routable virtually exclusively inside the cluster (as they rely) # on the cluster's DNS service, while the ip address is _sometimes_ # routable from the outside, e.g., when deploying on MicroK8s on Linux. - scheme = "https" if self.server_cert.server_cert else "http" - return f"{scheme}://{self.hostname}:{self._port}" + return self.internal_url @property def scrape_jobs(self) -> List[Dict[str, Any]]: @@ -582,6 +591,7 @@ def _update_cert(self): ) # Repeat for the charm container. We need it there for loki client requests. + # (and charm tracing and logging TLS) ca_cert_path.parent.mkdir(exist_ok=True, parents=True) ca_cert_path.write_text(self.server_cert.ca_cert) # pyright: ignore else: @@ -714,7 +724,7 @@ def _check_alert_rules(self): ssl_context = ssl.create_default_context( cafile=self._ca_cert_path if Path(self._ca_cert_path).exists() else None, ) - url = f"{self._internal_url}/loki/api/v1/rules" + url = f"{self._internal_url}{self._loki_rules_endpoint}" try: logger.debug(f"Verifying alert rules via {url}.") urllib.request.urlopen(url, timeout=2.0, context=ssl_context) @@ -784,6 +794,15 @@ def tracing_endpoint(self) -> Optional[str]: return self.tracing.get_endpoint("otlp_http") return None + @property + def logging_endpoints(self) -> List[str]: + """Loki endpoint for charm logging.""" + container = self._loki_container + if container.can_connect() and container.get_service(self._name).is_running(): + scheme = "https" if self.server_ca_cert_path else "http" + return [f"{scheme}://localhost:3100" + self._loki_push_api_endpoint] + return [] + @property def server_ca_cert_path(self) -> Optional[str]: """Server CA certificate path for TLS tracing.""" diff --git a/tests/integration/loki-tester/src/charm.py b/tests/integration/loki-tester/src/charm.py index 99e3929cd..2d0eb212b 100755 --- a/tests/integration/loki-tester/src/charm.py +++ b/tests/integration/loki-tester/src/charm.py @@ -24,7 +24,6 @@ def __init__(self, *args): super().__init__(*args) self._loki_consumer = LokiPushApiConsumer(self) - self.framework.observe(self.on.config_changed, self._on_config_changed) self.framework.observe(self.on.update_status, self._on_update_status) self.framework.observe(self.on.log_error_action, self._on_log_error_action) diff --git a/tests/integration/test_log_proxy_send_logs.py b/tests/integration/test_log_proxy_send_logs.py index 51d49ead3..a900a379b 100644 --- a/tests/integration/test_log_proxy_send_logs.py +++ b/tests/integration/test_log_proxy_send_logs.py @@ -24,11 +24,13 @@ ) } +loki_app_name = "loki" +tester_app_name = "log-proxy-tester" + +@pytest.mark.setup @pytest.mark.abort_on_fail -async def test_check_both_containers_send_logs(ops_test, loki_charm, log_proxy_tester_charm): - loki_app_name = "loki" - tester_app_name = "log-proxy-tester" +async def test_setup(ops_test, loki_charm, log_proxy_tester_charm): app_names = [loki_app_name, tester_app_name] await asyncio.gather( @@ -44,7 +46,7 @@ async def test_check_both_containers_send_logs(ops_test, loki_charm, log_proxy_t application_name=tester_app_name, ), ) - await ops_test.model.wait_for_idle(apps=app_names, status="active") + await ops_test.model.wait_for_idle(apps=app_names, status="active", raise_on_error=False) # Generate log files in the containers await generate_log_file( @@ -60,15 +62,25 @@ async def test_check_both_containers_send_logs(ops_test, loki_charm, log_proxy_t await ops_test.model.add_relation(loki_app_name, tester_app_name) await ops_test.model.wait_for_idle(apps=[loki_app_name, tester_app_name], status="active") + +@pytest.mark.work +async def test_series_found(ops_test): series = await loki_endpoint_request(ops_test, loki_app_name, "loki/api/v1/series", 0) data_series = json.loads(series)["data"] - assert len(data_series) == 3 + found = 0 for data in data_series: - assert data["container"] in ["workload-a", "workload-b"] - assert data["juju_application"] == tester_app_name - assert data["filename"] in [ - "/tmp/worload-a-1.log", - "/tmp/worload-a-2.log", - "/tmp/worload-b.log", - ] + # filter out the series we generated from those written by charm logging + if ( + data.get("container") in ["workload-a", "workload-b"] + and data["juju_application"] == tester_app_name + and data["filename"] + in [ + "/tmp/worload-a-1.log", + "/tmp/worload-a-2.log", + "/tmp/worload-b.log", + ] + ): + found += 1 + + assert found == 3 diff --git a/tests/scenario/conftest.py b/tests/scenario/conftest.py new file mode 100644 index 000000000..2cee37e94 --- /dev/null +++ b/tests/scenario/conftest.py @@ -0,0 +1,27 @@ +from unittest.mock import PropertyMock, patch + +import pytest +import scenario +from charm import LokiOperatorCharm + + +def tautology(*_, **__) -> bool: + return True + + +@pytest.fixture +def loki_charm(): + with patch.multiple( + "charm.KubernetesComputeResourcesPatch", + _namespace=PropertyMock("test-namespace"), + _patch=PropertyMock(tautology), + is_ready=PropertyMock(tautology), + ): + with patch("socket.getfqdn", new=lambda *args: "fqdn"): + with patch("lightkube.core.client.GenericSyncClient"): + yield LokiOperatorCharm + + +@pytest.fixture +def context(loki_charm): + return scenario.Context(loki_charm) diff --git a/tests/scenario/test_charm_logging.py b/tests/scenario/test_charm_logging.py new file mode 100644 index 000000000..993cfc45c --- /dev/null +++ b/tests/scenario/test_charm_logging.py @@ -0,0 +1,88 @@ +import logging +from unittest.mock import patch + +import ops.pebble +import pytest +import scenario + + +@pytest.fixture +def loki_emitter(): + with patch("charms.loki_k8s.v0.charm_logging.LokiHandler.emit") as h: + yield h + + +def test_no_endpoints_on_loki_not_ready(context, loki_emitter): + state = scenario.State( + containers=[ + scenario.Container( + "loki", + can_connect=True, + layers={"loki": ops.pebble.Layer({"services": {"loki": {}}})}, + service_status={"loki": ops.pebble.ServiceStatus.INACTIVE}, + exec_mock={("update-ca-certificates", "--fresh"): scenario.ExecOutput()}, + ) + ] + ) + + with context.manager("update-status", state) as mgr: + charm = mgr.charm + assert charm.logging_endpoints == [] + logging.getLogger("foo").debug("bar") + + loki_emitter.assert_not_called() + + +def test_endpoints_on_loki_ready(context, loki_emitter): + state = scenario.State( + containers=[ + scenario.Container( + "loki", + can_connect=True, + layers={"loki": ops.pebble.Layer({"services": {"loki": {}}})}, + service_status={"loki": ops.pebble.ServiceStatus.ACTIVE}, + exec_mock={("update-ca-certificates", "--fresh"): scenario.ExecOutput()}, + ) + ] + ) + + with context.manager("update-status", state) as mgr: + charm = mgr.charm + assert charm.logging_endpoints == ["http://localhost:3100/loki/api/v1/push"] + logging.getLogger("foo").debug("bar") + + loki_emitter.assert_called() + + for call in loki_emitter.call_args_list: + record = call.args[0] + if record.filename == __name__ + ".py": # log emitted by this module + assert record.msg == "bar" + assert record.name == "foo" + + +@patch("charm.LokiOperatorCharm.server_ca_cert_path", new_callable=lambda *_: True) +def test_endpoints_on_loki_ready_tls(_, context, loki_emitter): + state = scenario.State( + containers=[ + scenario.Container( + "loki", + can_connect=True, + layers={"loki": ops.pebble.Layer({"services": {"loki": {}}})}, + service_status={"loki": ops.pebble.ServiceStatus.ACTIVE}, + exec_mock={("update-ca-certificates", "--fresh"): scenario.ExecOutput()}, + ) + ] + ) + + with context.manager("update-status", state) as mgr: + charm = mgr.charm + assert charm.logging_endpoints == ["https://localhost:3100/loki/api/v1/push"] + logging.getLogger("foo").debug("bar") + + loki_emitter.assert_called() + + for call in loki_emitter.call_args_list: + record = call.args[0] + if record.filename == __name__ + ".py": # log emitted by this module + assert record.msg == "bar" + assert record.name == "foo" diff --git a/tox.ini b/tox.ini index c9d2e6341..f3bcf0796 100644 --- a/tox.ini +++ b/tox.ini @@ -81,16 +81,13 @@ commands = -m pytest -v --tb native --log-cli-level=INFO -s {posargs} {[vars]tst_path}/unit coverage report -# Added a '-disabled' suffix so CI won't fail on scenario tests, due to -# - https://github.com/canonical/ops-scenario/issues/48 -# - https://github.com/canonical/ops-scenario/issues/49 -[testenv:scenario-disabled] +[testenv:scenario] description = Scenario tests deps = pytest pydantic>=2 ops-scenario - ops < 2.5.0 # https://github.com/canonical/ops-scenario/issues/48 + ops opentelemetry-exporter-otlp-proto-http==1.21.0 # PYDEPS for tracing importlib-metadata==6.0.0 # PYDEPS for tracing -r{toxinidir}/requirements.txt