From 43386b15fa0f3ba4ca7863efe626dd97f8a2328a Mon Sep 17 00:00:00 2001 From: Nikolay Tatarinov Date: Mon, 2 Mar 2026 23:15:22 +0300 Subject: [PATCH] feat: add configurable logging level for backend and Mini App - Introduced a new `LOG_LEVEL` configuration option in the `.env.example` file to allow users to set the logging level (DEBUG, INFO, WARNING, ERROR). - Updated the `Settings` class to include the `log_level` attribute, normalizing its value to ensure valid logging levels are used. - Modified the logging setup in `run.py` to utilize the configured log level, enhancing flexibility in log management. - Enhanced the Mini App to include the logging level in the JavaScript configuration, allowing for consistent logging behavior across the application. - Added a new `logger.js` module for frontend logging, implementing level-based filtering and console delegation. - Included unit tests for the new logger functionality to ensure proper behavior and level handling. --- .env.example | 3 ++ docs/configuration.md | 1 + duty_teller/api/app.py | 17 ++++-- duty_teller/api/dependencies.py | 1 + duty_teller/config.py | 13 +++++ duty_teller/run.py | 2 +- tests/test_api_dependencies.py | 4 +- tests/test_app.py | 4 +- webapp/css/calendar.css | 5 -- webapp/index.html | 1 + webapp/js/api.js | 9 ++++ webapp/js/auth.js | 8 ++- webapp/js/i18n.js | 2 +- webapp/js/logger.js | 71 +++++++++++++++++++++++++ webapp/js/logger.test.js | 94 +++++++++++++++++++++++++++++++++ webapp/js/main.js | 6 +++ 16 files changed, 226 insertions(+), 15 deletions(-) create mode 100644 webapp/js/logger.js create mode 100644 webapp/js/logger.test.js diff --git a/.env.example b/.env.example index bb36433..edbf036 100644 --- a/.env.example +++ b/.env.example @@ -26,6 +26,9 @@ ADMIN_USERNAMES=admin1,admin2 # When the pinned duty message is updated on schedule, re-pin so members get a notification (default: 1). Set to 0 or false to disable. # DUTY_PIN_NOTIFY=1 +# Log level for backend and Mini App console logs: DEBUG, INFO, WARNING, ERROR. Default: INFO. +# LOG_LEVEL=INFO + # Single source of language for bot, API, and Mini App (en or ru). Default: en. No auto-detection. # DEFAULT_LANGUAGE=en diff --git a/docs/configuration.md b/docs/configuration.md index 43bd72b..89ea2f8 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -20,6 +20,7 @@ All configuration is read from the environment (e.g. `.env` via python-dotenv). | **DUTY_DISPLAY_TZ** | string (timezone name) | `Europe/Moscow` | Timezone for the pinned duty message in groups. Example: `Europe/Moscow`, `UTC`. | | **DUTY_PIN_NOTIFY** | `0`, `false`, or `no` to disable | `1` (enabled) | When the pinned duty message is updated on schedule, the bot sends a new message, unpins the old one and pins the new one. If enabled, pinning the new message sends a Telegram notification (“Bot pinned a message”). Set to `0`, `false`, or `no` to pin without notification. The first pin (e.g. when the bot is added to the group or on `/pin_duty`) is always silent. | | **DEFAULT_LANGUAGE** | `en` or `ru` (normalized) | `en` | **Single source of language for the whole deployment:** bot messages, API error texts, and Mini App UI all use this value. No auto-detection from Telegram user, browser, or `Accept-Language`. Values starting with `ru` are normalized to `ru`; anything else becomes `en`. | +| **LOG_LEVEL** | `DEBUG`, `INFO`, `WARNING`, or `ERROR` | `INFO` | Logging level for the backend (Python `logging`) and for the Mini App console logger (`window.__DT_LOG_LEVEL`). Use `DEBUG` for troubleshooting; in production `INFO` or higher is recommended. | ## Roles and access diff --git a/duty_teller/api/app.py b/duty_teller/api/app.py index 21d17ed..337ca19 100644 --- a/duty_teller/api/app.py +++ b/duty_teller/api/app.py @@ -93,7 +93,11 @@ class NoCacheStaticMiddleware: headers[idx] = (b"vary", existing + b", " + vary_val) else: headers.append((b"vary", vary_val)) - message = {"type": "http.response.start", "status": message["status"], "headers": headers} + message = { + "type": "http.response.start", + "status": message["status"], + "headers": headers, + } await send(message) await self.app(scope, receive, send_wrapper) @@ -104,13 +108,16 @@ app.add_middleware(NoCacheStaticMiddleware) @app.get( "/app/config.js", - summary="Mini App config (language)", - description="Returns JS that sets window.__DT_LANG from DEFAULT_LANGUAGE. Loaded before main.js.", + summary="Mini App config (language, log level)", + description=( + "Returns JS that sets window.__DT_LANG and window.__DT_LOG_LEVEL. Loaded before main.js." + ), ) def app_config_js() -> Response: - """Return JS assigning window.__DT_LANG for the webapp. No caching.""" + """Return JS assigning window.__DT_LANG and window.__DT_LOG_LEVEL for the webapp. No caching.""" lang = config.DEFAULT_LANGUAGE - body = f'window.__DT_LANG = "{lang}";' + log_level = config.LOG_LEVEL_STR.lower() + body = f'window.__DT_LANG = "{lang}";\nwindow.__DT_LOG_LEVEL = "{log_level}";' return Response( content=body, media_type="application/javascript; charset=utf-8", diff --git a/duty_teller/api/dependencies.py b/duty_teller/api/dependencies.py index f032598..ea2c657 100644 --- a/duty_teller/api/dependencies.py +++ b/duty_teller/api/dependencies.py @@ -20,6 +20,7 @@ from duty_teller.utils.dates import DateRangeValidationError, validate_date_rang log = logging.getLogger(__name__) + def _lang_from_accept_language(header: str | None) -> str: """Return the application language: always config.DEFAULT_LANGUAGE. diff --git a/duty_teller/config.py b/duty_teller/config.py index d50cb55..63afee8 100644 --- a/duty_teller/config.py +++ b/duty_teller/config.py @@ -4,6 +4,7 @@ BOT_TOKEN is not validated on import; call require_bot_token() in the entry poin when running the bot. """ +import logging import os import re from dataclasses import dataclass @@ -46,6 +47,14 @@ def _parse_phone_list(raw: str) -> set[str]: return result +def _normalize_log_level(raw: str) -> str: + """Return a valid log level name (DEBUG, INFO, WARNING, ERROR); default INFO.""" + level = (raw or "").strip().upper() + if level in ("DEBUG", "INFO", "WARNING", "ERROR"): + return level + return "INFO" + + @dataclass(frozen=True) class Settings: """Injectable settings built from environment. Used in tests or when env is overridden.""" @@ -67,6 +76,7 @@ class Settings: duty_display_tz: str default_language: str duty_pin_notify: bool + log_level: str @classmethod def from_env(cls) -> "Settings": @@ -118,6 +128,7 @@ class Settings: default_language=normalize_lang(os.getenv("DEFAULT_LANGUAGE", "en")), duty_pin_notify=os.getenv("DUTY_PIN_NOTIFY", "1").strip().lower() not in ("0", "false", "no"), + log_level=_normalize_log_level(os.getenv("LOG_LEVEL", "INFO")), ) @@ -141,6 +152,8 @@ EXTERNAL_CALENDAR_ICS_URL = _settings.external_calendar_ics_url DUTY_DISPLAY_TZ = _settings.duty_display_tz DEFAULT_LANGUAGE = _settings.default_language DUTY_PIN_NOTIFY = _settings.duty_pin_notify +LOG_LEVEL = getattr(logging, _settings.log_level.upper(), logging.INFO) +LOG_LEVEL_STR = _settings.log_level def is_admin(username: str) -> bool: diff --git a/duty_teller/run.py b/duty_teller/run.py index 1c280ce..9e8ac5c 100644 --- a/duty_teller/run.py +++ b/duty_teller/run.py @@ -24,7 +24,7 @@ async def _resolve_bot_username(application) -> None: logging.basicConfig( format="%(asctime)s - %(name)s - %(levelname)s - %(message)s", - level=logging.INFO, + level=config.LOG_LEVEL, ) logger = logging.getLogger(__name__) diff --git a/tests/test_api_dependencies.py b/tests/test_api_dependencies.py index 599b10b..043cd51 100644 --- a/tests/test_api_dependencies.py +++ b/tests/test_api_dependencies.py @@ -17,7 +17,9 @@ class TestLangFromAcceptLanguage: assert deps._lang_from_accept_language(None) == config.DEFAULT_LANGUAGE assert deps._lang_from_accept_language("") == config.DEFAULT_LANGUAGE assert deps._lang_from_accept_language(" ") == config.DEFAULT_LANGUAGE - assert deps._lang_from_accept_language("ru-RU,ru;q=0.9") == config.DEFAULT_LANGUAGE + assert ( + deps._lang_from_accept_language("ru-RU,ru;q=0.9") == config.DEFAULT_LANGUAGE + ) assert deps._lang_from_accept_language("en-US") == config.DEFAULT_LANGUAGE assert deps._lang_from_accept_language("zz") == config.DEFAULT_LANGUAGE assert deps._lang_from_accept_language("x") == config.DEFAULT_LANGUAGE diff --git a/tests/test_app.py b/tests/test_app.py index c78d202..4910b10 100644 --- a/tests/test_app.py +++ b/tests/test_app.py @@ -35,7 +35,9 @@ def test_app_static_has_no_store_and_vary(client): r = client.get("/app/") if r.status_code != 200: r = client.get("/app") - assert r.status_code == 200, "webapp static mount should serve index at /app or /app/" + assert r.status_code == 200, ( + "webapp static mount should serve index at /app or /app/" + ) assert r.headers.get("cache-control") == "no-store" assert "accept-language" in r.headers.get("vary", "").lower() diff --git a/webapp/css/calendar.css b/webapp/css/calendar.css index 6551267..e6fb517 100644 --- a/webapp/css/calendar.css +++ b/webapp/css/calendar.css @@ -86,11 +86,6 @@ padding-bottom: 12px; margin-bottom: 4px; touch-action: pan-y; - transition: box-shadow var(--transition-fast) ease-out; -} - -.calendar-sticky.is-scrolled { - box-shadow: 0 2px 8px rgba(0, 0, 0, 0.15); } .calendar { diff --git a/webapp/index.html b/webapp/index.html index f2b11a8..5e7d1c6 100644 --- a/webapp/index.html +++ b/webapp/index.html @@ -58,6 +58,7 @@ "./js/dutyList.js": "./js/dutyList.js?v=2", "./js/hints.js": "./js/hints.js?v=2", "./js/i18n.js": "./js/i18n.js?v=3", + "./js/logger.js": "./js/logger.js?v=1", "./js/theme.js": "./js/theme.js?v=2", "./js/ui.js": "./js/ui.js?v=2", "./js/utils.js": "./js/utils.js?v=2" diff --git a/webapp/js/api.js b/webapp/js/api.js index c7d2d1d..9b1156f 100644 --- a/webapp/js/api.js +++ b/webapp/js/api.js @@ -6,6 +6,7 @@ import { FETCH_TIMEOUT_MS } from "./constants.js"; import { getInitData } from "./auth.js"; import { state } from "./dom.js"; import { t } from "./i18n.js"; +import { logger } from "./logger.js"; /** * Build fetch options with init data header, Accept-Language and timeout abort. @@ -49,10 +50,17 @@ export async function apiGet(path, params = {}, options = {}) { const query = new URLSearchParams(params).toString(); const url = query ? `${base}${path}?${query}` : `${base}${path}`; const initData = getInitData(); + logger.debug("API request", path, params); const opts = buildFetchOptions(initData, options.signal); try { const res = await fetch(url, { headers: opts.headers, signal: opts.signal }); + if (!res.ok) { + logger.warn("API non-OK response", path, res.status); + } return res; + } catch (e) { + logger.error("API request failed", path, e); + throw e; } finally { opts.cleanup(); } @@ -69,6 +77,7 @@ export async function apiGet(path, params = {}, options = {}) { export async function fetchDuties(from, to, signal) { const res = await apiGet("/api/duties", { from, to }, { signal }); if (res.status === 403) { + logger.warn("Access denied", from, to); let detail = t(state.lang, "access_denied"); try { const body = await res.json(); diff --git a/webapp/js/auth.js b/webapp/js/auth.js index 1f5dd10..595095f 100644 --- a/webapp/js/auth.js +++ b/webapp/js/auth.js @@ -2,6 +2,8 @@ * Telegram init data and access checks. */ +import { logger } from "./logger.js"; + /** * Get tgWebAppData value from hash when it contains unencoded & and =. * Value runs from tgWebAppData= until next &tgWebApp or end. @@ -33,7 +35,10 @@ export function getInitData() { const hash = window.location.hash ? window.location.hash.slice(1) : ""; if (hash) { const fromHash = getTgWebAppDataFromHash(hash); - if (fromHash) return fromHash; + if (fromHash) { + logger.debug("initData from hash"); + return fromHash; + } const hashParams = new URLSearchParams(hash); const tgFromHash = hashParams.get("tgWebAppData"); if (tgFromHash) return tgFromHash; @@ -42,6 +47,7 @@ export function getInitData() { ? new URLSearchParams(window.location.search).get("tgWebAppData") : null; if (q) { + logger.debug("initData from query"); return q; } return ""; diff --git a/webapp/js/i18n.js b/webapp/js/i18n.js index 724cea5..ce55da4 100644 --- a/webapp/js/i18n.js +++ b/webapp/js/i18n.js @@ -110,7 +110,7 @@ export const MESSAGES = { "contact.back": "Назад", "contact.phone": "Телефон", "contact.telegram": "Telegram", - "current_duty.title": "Текущее дежурство", + "current_duty.title": "Сейчас дежурит", "current_duty.no_duty": "Сейчас никто не дежурит", "current_duty.shift": "Смена", "current_duty.remaining": "Осталось: {hours}ч {minutes}мин", diff --git a/webapp/js/logger.js b/webapp/js/logger.js new file mode 100644 index 0000000..2d73595 --- /dev/null +++ b/webapp/js/logger.js @@ -0,0 +1,71 @@ +/** + * Frontend logger with configurable level (window.__DT_LOG_LEVEL). + * Only messages at or above the configured level are forwarded to console. + * Prefix [DutyTeller][level] for DevTools filtering. + */ + +const LEVEL_ORDER = { debug: 0, info: 1, warn: 2, error: 3 }; + +/** + * Resolve current log level from window.__DT_LOG_LEVEL. Default: info. + * @returns {string} One of "debug", "info", "warn", "error" + */ +function getLogLevel() { + const raw = + (typeof window !== "undefined" && window.__DT_LOG_LEVEL) || "info"; + const level = String(raw).toLowerCase(); + return LEVEL_ORDER.hasOwnProperty(level) ? level : "info"; +} + +/** + * Return true if message at level should be emitted (level >= configured). + * @param {string} messageLevel - "debug" | "info" | "warn" | "error" + * @returns {boolean} + */ +function shouldLog(messageLevel) { + const configured = getLogLevel(); + const configuredNum = LEVEL_ORDER[configured] ?? 1; + const messageNum = LEVEL_ORDER[messageLevel] ?? 1; + return messageNum >= configuredNum; +} + +const PREFIX = "[DutyTeller]"; + +function logAt(level, args) { + if (!shouldLog(level)) return; + const consoleMethod = + level === "debug" + ? console.debug + : level === "info" + ? console.info + : level === "warn" + ? console.warn + : console.error; + const prefix = `${PREFIX}[${level}]`; + if (args.length === 0) { + consoleMethod(prefix); + } else if (args.length === 1) { + consoleMethod(prefix, args[0]); + } else { + consoleMethod(prefix, ...args); + } +} + +/** + * Logger object with debug, info, warn, error (signature like console). + * Example: logger.info("Loaded", { count: 5 }); + */ +export const logger = { + debug(msg, ...args) { + logAt("debug", [msg, ...args]); + }, + info(msg, ...args) { + logAt("info", [msg, ...args]); + }, + warn(msg, ...args) { + logAt("warn", [msg, ...args]); + }, + error(msg, ...args) { + logAt("error", [msg, ...args]); + }, +}; diff --git a/webapp/js/logger.test.js b/webapp/js/logger.test.js new file mode 100644 index 0000000..18d2049 --- /dev/null +++ b/webapp/js/logger.test.js @@ -0,0 +1,94 @@ +/** + * Unit tests for logger: level filtering and console delegation. + */ + +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { logger } from "./logger.js"; + +describe("logger", () => { + const origWindow = globalThis.window; + + beforeEach(() => { + vi.spyOn(console, "debug").mockImplementation(() => {}); + vi.spyOn(console, "info").mockImplementation(() => {}); + vi.spyOn(console, "warn").mockImplementation(() => {}); + vi.spyOn(console, "error").mockImplementation(() => {}); + }); + + afterEach(() => { + vi.restoreAllMocks(); + if (globalThis.window) { + delete globalThis.window.__DT_LOG_LEVEL; + } + }); + + function setLevel(level) { + if (!globalThis.window) globalThis.window = {}; + globalThis.window.__DT_LOG_LEVEL = level; + } + + it("at level info does not call console.debug", () => { + setLevel("info"); + logger.debug("test"); + expect(console.debug).not.toHaveBeenCalled(); + }); + + it("at level info calls console.info for logger.info", () => { + setLevel("info"); + logger.info("hello"); + expect(console.info).toHaveBeenCalledWith("[DutyTeller][info]", "hello"); + }); + + it("at level info calls console.warn and console.error", () => { + setLevel("info"); + logger.warn("w"); + logger.error("e"); + expect(console.warn).toHaveBeenCalledWith("[DutyTeller][warn]", "w"); + expect(console.error).toHaveBeenCalledWith("[DutyTeller][error]", "e"); + }); + + it("at level debug calls console.debug", () => { + setLevel("debug"); + logger.debug("dbg"); + expect(console.debug).toHaveBeenCalledWith("[DutyTeller][debug]", "dbg"); + }); + + it("at level error does not call console.debug or console.info", () => { + setLevel("error"); + logger.debug("d"); + logger.info("i"); + expect(console.debug).not.toHaveBeenCalled(); + expect(console.info).not.toHaveBeenCalled(); + }); + + it("at level error calls console.error", () => { + setLevel("error"); + logger.error("err"); + expect(console.error).toHaveBeenCalledWith("[DutyTeller][error]", "err"); + }); + + it("passes extra args to console", () => { + setLevel("info"); + logger.info("msg", { foo: 1 }, "bar"); + expect(console.info).toHaveBeenCalledWith( + "[DutyTeller][info]", + "msg", + { foo: 1 }, + "bar" + ); + }); + + it("defaults to info when __DT_LOG_LEVEL is missing", () => { + if (globalThis.window) delete globalThis.window.__DT_LOG_LEVEL; + logger.debug("no"); + expect(console.debug).not.toHaveBeenCalled(); + logger.info("yes"); + expect(console.info).toHaveBeenCalledWith("[DutyTeller][info]", "yes"); + }); + + it("defaults to info when __DT_LOG_LEVEL is invalid", () => { + setLevel("invalid"); + logger.debug("no"); + expect(console.debug).not.toHaveBeenCalled(); + }); +}); diff --git a/webapp/js/main.js b/webapp/js/main.js index 6fafc7a..099bf06 100644 --- a/webapp/js/main.js +++ b/webapp/js/main.js @@ -17,6 +17,7 @@ import { } from "./dom.js"; import { showAccessDenied, hideAccessDenied, showError, setNavEnabled } from "./ui.js"; import { fetchDuties, fetchCalendarEvents } from "./api.js"; +import { logger } from "./logger.js"; import { dutiesByDate, calendarEventsByDate, @@ -65,6 +66,8 @@ export function applyLangToUi() { applyLangToUi(); +logger.info("App init", "lang=" + state.lang); + window.__dtReady = true; /** @@ -148,6 +151,7 @@ async function loadMonth() { const from = localDateString(start); const to = localDateString(gridEnd); try { + logger.debug("Loading month", from, to); const dutiesPromise = fetchDuties(from, to, signal); const eventsPromise = fetchCalendarEvents(from, to, signal); const duties = await dutiesPromise; @@ -186,6 +190,7 @@ async function loadMonth() { return; } if (e.message === "ACCESS_DENIED") { + logger.warn("Access denied in loadMonth", e.serverDetail); showAccessDenied(e.serverDetail); setNavEnabled(true); if ( @@ -198,6 +203,7 @@ async function loadMonth() { } return; } + logger.error("Load month failed", e); showError(e.message || t(state.lang, "error_generic"), loadMonth); setNavEnabled(true); return;