Шум і безпека логів: verbose, лінивий DEBUG і маскування

1. Шум у логах: чому це болить

Коли ви починаєте писати логи, зазвичай проходите типову стадію: «логуймо все, а потім розберемося». Це як поставити в кімнаті десять будильників «про всяк випадок» — у підсумку ви прокидаєтеся не раніше, зате в паніці. Шум у логах — це ситуація, коли важливі події (помилка, попередження, ключовий крок сценарію) губляться серед десятків рядків на кшталт «ми зайшли у функцію», «ми вийшли з функції», «ми прочитали пробіл».

Проблема шуму не лише естетична. Надто докладні логи ускладнюють діагностику: ви витрачаєте час на пошук, а мозок перевантажується схожими повідомленнями. До того ж надмірне логування інколи помітно сповільнює програму (навіть консольну). Рядкова інтерполяція, збирання великих повідомлень, формування контексту — усе це робота, яку ви виконуєте навіть тоді, коли потім вирішуєте ці повідомлення не показувати.

Щоб було простіше мислити, зручно уявляти рівні логування не як «гарні слова», а як домовленість:

DEBUG

INFO

WARN

ERROR

Наша мета сьогодні — навчитися вмикати й вимикати деталі без переписування програми та без «ручного коментування println». А ще — привчитися не писати зайвого (особливо зайвого й небезпечного).

2. Режим докладних логів

Прапорець verbose і вибір minLevel

Verbose-режим — це простий перемикач «більше деталей». У консольних застосунках його дуже зручно прив’язати до аргументів запуску. Запускаємо як зазвичай — бачимо INFO/WARN/ERROR. Запускаємо з "--verbose" — бачимо ще й DEBUG. Це не «фіча для великих компаній», а найпростіший спосіб не засмічувати вивід у звичайному сценарії й вмикати докладність, коли щось пішло не так.

Почнемо з найпростішої перевірки: чи є "--verbose" серед аргументів main(args: Array<String>). У Kotlin це робиться майже як українською:

fun isVerbose(args: Array<String>): Boolean =
    args.contains("--verbose")

Тепер пов’язуємо verbose з мінімальним рівнем логування. Якщо verbose вимкнено — логуємо, починаючи з INFO. Якщо ввімкнено — починаючи з DEBUG.

fun chooseMinLevel(args: Array<String>): LogLevel {
    return if (isVerbose(args)) LogLevel.DEBUG else LogLevel.INFO
}

І вже в main створюємо логер:

fun main(args: Array<String>) {
    val logger = Logger(minLevel = chooseMinLevel(args))

    logger.info("Застосунок запущено")      // виведеться майже завжди
    logger.debug { "Деталі..." }   // виведеться тільки з --verbose
}

На цьому місці зазвичай виникає питання: «Чому не зробити за замовчуванням DEBUG і не перейматися?» Тому що тоді ви швидко перестанете читати логи. А якщо розробник перестає їх читати, логи перетворюються на декорацію: гарну, але марну.

Лінивий DEBUG: debug { ... } замість debug("...$heavy")

Навіть якщо ви фільтруєте за рівнем, є підступна пастка: повідомлення часто будується ще до того, як логер вирішить його друкувати. Наприклад, інтерполяція рядків у Kotlin виконує роботу одразу:

logger.debug { "state=${heavyStateDump()}" } // так правильно: обчислиться тільки в DEBUG

Якщо ж ви напишете «раннє» збирання рядка, обчислення почнуться незалежно від того, увімкнено DEBUG чи ні:

val message = "state=${heavyStateDump()}" // heavyStateDump() викличеться завжди
logger.debug { message }

У маленьких прикладах цього не помітно, але в реальних програмах (особливо коли ви робите joinToString, серіалізацію або форматування таблиць) це може стати неприємним сюрпризом. Ви наче «не друкуєте», але все одно витрачаєте процесорний час, пам’ять і час виконання.

Рішення — зробити debug лінивим: приймати не String, а лямбду () -> String і викликати її лише тоді, коли рівень увімкнено.

Нижче — компактна версія логера з лінивим DEBUG і підтримкою контексту. Важливий момент: контекст форматуємо централізовано, щоб не повторювати цей код у кожному місці.

enum class LogLevel { DEBUG, INFO, WARN, ERROR }

class Logger(private val minLevel: LogLevel) {

    private fun isEnabled(level: LogLevel): Boolean =
        level.ordinal >= minLevel.ordinal

    fun debug(message: () -> String, ctx: Map<String, String> = emptyMap()) {
        if (!isEnabled(LogLevel.DEBUG)) return
        log(LogLevel.DEBUG, message(), ctx)
    }

    fun info(message: String, ctx: Map<String, String> = emptyMap()) =
        log(LogLevel.INFO, message, ctx)

    fun warn(message: String, ctx: Map<String, String> = emptyMap()) =
        log(LogLevel.WARN, message, ctx)

    fun error(message: String, ctx: Map<String, String> = emptyMap()) =
        log(LogLevel.ERROR, message, ctx)

    private fun log(level: LogLevel, message: String, ctx: Map<String, String>) {
        if (!isEnabled(level)) return
        val ts = System.currentTimeMillis()
        println("$ts [$level] $message${formatCtx(ctx)}")
    }

    private fun formatCtx(ctx: Map<String, String>): String {
        val safe = sanitizeCtx(ctx)
        if (safe.isEmpty()) return ""
        return safe.entries.joinToString(prefix = " ", separator = " ") { (k, v) -> "$k=$v" }
    }

    private fun sanitizeCtx(ctx: Map<String, String>): Map<String, String> {
        return ctx.mapValues { (k, v) ->
            if (looksSensitiveKey(k)) maskSecret(v) else v
        }
    }

    private fun looksSensitiveKey(key: String): Boolean {
        val k = key.lowercase()
        return k.contains("token") || k.contains("password") || k.contains("secret") || k.contains("api_key")
    }
}

До речі, якщо ви форматуєте контекст через joinToString(), це теж може бути «не безплатно». joinToString() — нормальний і читабельний інструмент збирання тексту з колекції, але краще не будувати підсумковий рядок без потреби, особливо в DEBUG. У прикладі вище це враховано: форматування відбудеться лише тоді, коли рівень справді друкується.

3. Де ставити лог, щоб він допоміг

Дуже хочеться дати правило «логуй усе на кожному кроці», але це як порада «щоб не загубити ключі, приклейте їх до руки скотчем». Формально ключі не загубляться, але жити стане складніше. У логуванні корисніше думати не про кількість рядків, а про змістові точки.

Хороша інтуїція така: INFO — це «великі віхи» сценарію, DEBUG — «внутрішні деталі», WARN — «підозріле, але прийнятне», ERROR — «нам не вдалося виконати дію». Тоді ви починаєте ставити логи не «всюди», а на межах.

Наприклад, обробка команди в консольному застосунку — чудовий кандидат на «межу операції». Там у вас є контекст (requestId, команда, аргументи), і там логічно:

• записати старт обробки (INFO),
• у DEBUG записати деталі розбору аргументів,
• за дивних вхідних даних дати WARN,
• за винятку або провалу — ERROR,
• записати завершення (INFO), можливо — із вимірюванням часу.

Внутрішні цикли, де ви перебираєте список із 1000 елементів, зазвичай не варто логувати на INFO — інакше ви отримаєте лог-флуд. Якщо дуже потрібно, ставте такий лог на DEBUG і робіть його лінивим (через лямбду). Інакше матимете і шум, і зайву вартість формування повідомлення.

4. Безпека: що не можна писати в логи

Найнебезпечніша фраза в історії розробки — «я це додам тимчасово, щоб налагодити». Тимчасовий код живе довше за багато стосунків, а логи інколи «виїжджають» у баг-репорти, в історію термінала, у CI, у скриншоти, у корпоративні чати. І от саме там і з’ясовується, що «тимчасово» ви логували пароль.

Важливо прийняти як правило: логи — публічніші, ніж здається. Навіть якщо у вас локальний консольний застосунок, ви самі можете надіслати лог другові, викладачеві або в тікет — і раптом це вже витік.

Найтиповіші «не можна» в логах:

• паролі, PIN-коди, одноразові коди (OTP),
• токени авторизації (API keys, bearer tokens),
• секретні ключі, приватні ключі,
• повні номери карток,
• інколи — електронна пошта або телефон (залежить від політики проєкту), але в навчальному проєкті краще тренувати звичку «не логувати зайвого».

Окрема неприємна категорія — контекст логів. Ми любимо його за структуру key=value, але це й пастка: ви можете машинально покласти туди token=..., бо «це ж контекст, а не повідомлення». Для безпеки немає різниці, де ви це написали: у тексті чи в контексті. Якщо воно потрапило у вивід, воно потрапило в лог.

5. Маскування даних: корисно й безпечно

Маскування — це компроміс: ми не хочемо зберігати секрет повністю, але хочемо мати змогу зрозуміти «це той самий токен чи інший». Тому часто лишають невеликий «хвіст», а решту замінюють на ****. Це дає змогу відрізнити token=...1234 від token=...9876, не розкриваючи весь секрет.

Почнемо з базової функції. Вона спеціально коротка, щоб вам було легко зрозуміти логіку й не потонути в «магії».

fun maskSecret(value: String): String {
    if (value.length <= 4) return "****"
    val tail = value.substring(value.length - 4)
    return "****$tail"
}

Приклад використання:

fun main() {
    val token = "abcd-efgh-ijkl-1234"
    println(maskSecret(token)) // ****1234
}

Далі — питання практики: «А як бути з контекстом?»

Ідея проста: якщо ключ у контексті виглядає як чутливий (token, password, secret), то значення потрібно маскувати автоматично. У цій лекції ми застосовуємо просте правило за назвою ключа. У реальних проєктах замість «містить слово token» можуть бути суворіші правила, але принцип той самий: безпека має бути за замовчуванням.

Зверніть увагу: маскування — не «раз і назавжди». Воно працює, якщо ви домовилися про ключі контексту. Якщо один розробник пише authToken, інший — token, а третій — t, автоматичне правило почне пропускати секрети. Тому в реальних проєктах зазвичай домовляються про назви ключів. У навчальному проєкті робимо те саме — лише без бюрократії.

6. Зшиваємо все разом: "--verbose" і безпечний контекст

Зараз ми акуратно зшиємо все докупи на прикладі невеликого фрагмента консольного застосунку. Сенс прикладу не в тому, щоб «написати цілу систему», а в тому, щоб побачити: verbose, лінивий debug і маскування справді поєднуються та не потребують героїзму.

Уявімо, що в нас є команда "login", яка приймає токен. У реальному житті токен логувати не можна. Але під час налагодження хочеться розуміти, що токен узагалі прийшов і який він «приблизно» (щоб відрізнити один від іншого). Отже, логуємо лише маску.

Спочатку зберемо контекст операції та requestId:

fun makeRequestId(): String = "req-${System.currentTimeMillis()}"

fun makeBaseCtx(requestId: String, command: String): Map<String, String> {
    return mapOf("requestId" to requestId, "command" to command)
}

Далі — обробник команди:

fun handleLogin(rawToken: String, logger: Logger) {
    val requestId = makeRequestId()
    val ctx = makeBaseCtx(requestId, "login")

    logger.info("Вхід розпочато", ctx)

    // Важливо: навіть у DEBUG пишемо лише маску, а не секрет повністю
    logger.debug({ "rawToken=${maskSecret(rawToken)}" }, ctx)

    logger.info("Вхід завершено", ctx)
}

Зверніть увагу на «психологічний» момент. Ми могли б написати безпечно й без лямбди (наприклад, зібрати рядок заздалегідь), але звичка «увесь debug — ліниво й акуратно» дисциплінує. Ви рідше припускаєтеся помилок, бо частіше ставите собі питання: що саме ви логуєте і коли це формується.

Тепер зберемо main, який вмикає verbose за прапорцем:

fun main(args: Array<String>) {
    val logger = Logger(minLevel = chooseMinLevel(args))

    val token = readln().trim()
    handleLogin(rawToken = token, logger = logger)
}

Під час звичайного запуску (INFO) користувач не побачить діагностичних деталей. У verbose-режимі ("--verbose") він побачить DEBUG-рядок із маскою токена. Це саме той баланс, який нам потрібен: за замовчуванням тихо, у разі проблем — докладно, але безпечно.

7. Типові помилки

Помилка №1: verbose увімкнено завжди, бо «так зручніше».
Коли DEBUG постійно ввімкнено, дуже швидко настає звикання: ви перестаєте відрізняти важливе від шуму. У результаті, коли виникає справжня проблема, ви знову йдете «додавати ще логів», хоча річ була не в кількості, а в дисципліні. Тримайте DEBUG як режим діагностики, а не як стиль життя.

Помилка №2: збирання важкого повідомлення навіть за вимкненого DEBUG.
На словах здається, що раз DEBUG вимкнено — «нічого не відбувається». Насправді обчислення можуть виконуватися, просто ви не бачите результату. У маленьких програмах це непомітно, але в реальній логіці (формування великих рядків, joinToString, серіалізація, форматування таблиць) ви платите за налагодження навіть у звичайному режимі. Робіть DEBUG лінивим: debug { ... } — і не збирайте рядок заздалегідь.

Помилка №3: маскування лише в одному місці, а далі «десь забудемо».
Якщо ви маскуєте секрети вручну в кожному виклику логера, рано чи пізно забудете це зробити. Найнадійніший шлях — санітизувати контекст і чутливі значення централізовано (усередині Logger або в одній утиліті), щоб безпека була «за замовчуванням».

Помилка №4: «я виведу токен лише в DEBUG, це ж безпечно».
DEBUG — не «секретний рівень». Це лише рівень деталізації. Логи можуть потрапити куди завгодно — незалежно від рівня. Якщо значення не можна показувати, його не можна показувати на жодному рівні. Максимум — маска або короткий ідентифікатор.

Помилка №5: логування помилок не тим рівнем, щоб «не лякати».
Іноді хочеться написати «ну це ж очікувана помилка, давайте INFO». Якщо помилка справді очікувана і сценарій коректно продовжується, можливо, це WARN (і то не завжди). Якщо сценарій провалився — це ERROR. Коли рівні використовуються чесно, потім значно легше фільтрувати події й розуміти, що відбувається.

1

Опитування

Логування, рівень 60, лекція 4

Недоступний

Логування

Логування та спостережуваність

Відкрити