listen_log never receives DEBUG messages

[Hubro]

What happened?

I'm using listen_log to ship all my log messages to Loki. Since I have practically infinite storage and easy log filtering, I want to always enable debug logging.

However, I can't get listen_log to receive any DEBUG messages. Here's my ExternalLogging app:

from datetime import datetime

import appdaemon.adbase
import httpx


class ExternalLogging(appdaemon.adbase.ADBase):
    def initialize(self) -> None:
        self.loki_endpoint = self.args["loki_endpoint"]
        self.adapi = self.get_ad_api()
        self.http = httpx.AsyncClient()
        self.adapi.set_log_level("NOTSET")

        self.adapi.listen_log(self.on_log, "NOTSET")

        self.adapi.log("Initialized external logging")

    async def on_log(
        self,
        app_name: str,
        timestamp: datetime,
        level: str,
        log_file: str,
        message: str,
        kwargs: dict[str, str],
    ) -> None:
        print(f"SHIPPING LOG MESSAGE WITH LEVEL: {level!r}")  # DELETE ME

        labels = {
            "host": "homeassistant",
            "source": "appdaemon",
            "app": app_name,
        }

        message = f"level={level} log_file={log_file} message={message}"

        ns = round(timestamp.timestamp() * 1_000_000_000)

        payload = {
            "streams": [
                {
                    "stream": labels,
                    "values": [[str(ns), message]],
                }
            ],
        }

        response = await self.http.post(self.loki_endpoint, json=payload, timeout=3)
        response.raise_for_status()

I have log_level: NOTSET in the config of all my apps, and I'm also running self.set_log_level("NOTSET") in all my app initialize functions, just to be 100% sure. I've also tried "DEBUG" in place of "NOTSET" in all these places.

The print statement in my on_log callback shows up in the "Log" tab of the AppDaemon plugin, and it shows that the callback is only receiving INFO, WARNING, ERROR and CRITICAL log messages. It's not receiving any DEBUG or NOTSET log messages.

Is this a bug or am I missing something?

Version

4.4.2

Installation type

Home Assistant add-on

Relevant log output

2024-04-14 11:32:56.228945 DEBUG bathroom_lights: DEBUG Initial value: self.present = True
2024-04-14 11:32:56.231849 INFO bathroom_lights: INFO Initial value: self.present = True
2024-04-14 11:32:56.235509 WARNING bathroom_lights: WARNING Initial value: self.present = True
2024-04-14 11:32:56.238991 ERROR bathroom_lights: ERROR Initial value: self.present = True
2024-04-14 11:32:56.242074 CRITICAL bathroom_lights: CRITICAL Initial value: self.present = True
SHIPPING LOG MESSAGE WITH LEVEL: 'INFO'
SHIPPING LOG MESSAGE WITH LEVEL: 'WARNING'
SHIPPING LOG MESSAGE WITH LEVEL: 'ERROR'
SHIPPING LOG MESSAGE WITH LEVEL: 'CRITICAL'

Relevant code in the app or config file that caused the issue

No response

Anything else?

No response

[jsl12]

Not sure what's going on with the logging callbacks, but generally functions like this (sending the logs somewhere) happen in Python with logging handlers.

This is an example of what I use to send the logs from a single app to Loki.

import asyncio
import logging.config
from logging import Handler, LogRecord

import aiohttp
from appdaemon.adapi import ADAPI


class LokiHandler(Handler):
    loop: asyncio.BaseEventLoop
    loki_url: str
    level: int | str = 0

    def __init__(self, loop: asyncio.BaseEventLoop, loki_url: str, level: int | str = 0) -> None:
        self.loop: asyncio.BaseEventLoop = loop
        self.loki_url: str = loki_url
        super().__init__(level)

    def emit(self, record: LogRecord) -> None:
        self.loop.create_task(self.send_to_loki(record))

    async def send_to_loki(self, record: LogRecord):
        message = self.format(record)
        ns = round(record.created * 1_000_000_000)

        # https://grafana.com/docs/loki/latest/reference/loki-http-api/#ingest-logs
        payload = {
            'streams': [
                {
                    'stream': {'appname': record.appname, 'level': record.levelname},
                    'values': [[str(ns), message]],
                }
            ]
        }

        async with aiohttp.ClientSession() as session:
            await session.post(self.loki_url, json=payload, timeout=3)


class LokiLogger(ADAPI):
    async def initialize(self):
        log_cfg = {
            'version': 1,
            'disable_existing_loggers': False,
            'handlers': {
                'loki': {
                    '()': 'loki.LokiHandler',
                    'loop': self.AD.loop,
                    'loki_url': self.args['loki_url'],
                }
            },
            'loggers': {self.logger.name: {'handlers': ['loki'], 'level': 'DEBUG'}},
        }

        # Use dictConfig in order to replace the logging configuration every time the app is reloaded
        # https://docs.python.org/3/library/logging.config.html#configuration-dictionary-schema
        logging.config.dictConfig(log_cfg)
        self.log('Logging from LokiLogger')