1. Введение
Когда вы только начинаете писать программы, кажется, что логи — это и есть диагностика. «Напечатаю побольше текста — и всё пойму». Через пару недель реальности выясняется, что «побольше текста» превращается в «побольше шума», а ответ на вопрос «почему программа тормозит» из логов добывается примерно как археология: кисточкой и со слезами.
Метрики — это другой тип наблюдаемости. Если логи рассказывают истории (иногда драматические), то метрики — это сухая статистика. Условно: логи отвечают «что произошло с этой командой», а метрики отвечают «сколько таких команд было за время жизни программы и сколько времени они занимали».
Удобно держать в голове простую табличку:
| Что наблюдаем | Логи | Метрики |
|---|---|---|
| Смысл | «События» | «Измерения» |
| Типичный вопрос | «Что пошло не так?» | «Как часто?» / «Как долго?» |
| Пример | |
|
| Риск | много шума | много цифр без смысла |
И важный практический момент: метрики не заменяют логи. Они дополняют их, как градусник дополняет жалобу «мне плохо». По одному числу нельзя понять всю историю, но можно быстро увидеть, что «температура 39» — это уже не «подумаешь, немного устал».
2. Тайминги в консольном приложении
Где в консольном приложении использовать тайминги
На старте легко впасть в крайность: начать измерять время каждой функции, каждого if и каждого взгляда на переменную. Это не метрики, это тревожность, записанная в коде. В консольном приложении нам полезны тайминги на границах операций, то есть там, где пользователь действительно инициировал действие: обработка команды, построение отчёта, импорт/экспорт, вычисление статистики.
Чтобы это было конкретно, будем продолжать наш учебный CLI‑проект (условно назовём его ExpenseTracker). В нём пользователь вводит команды вроде add, list, remove, total. Логи у нас уже умеют уровни, контекст и печать ошибок. Теперь мы хотим измерять, например, сколько времени занимает обработка каждой команды и как часто команды вызываются.
Схема процесса получится примерно такая:
flowchart LR
U[Пользователь вводит команду] --> C[CLI: parse/dispatch]
C --> S[Сценарий/сервис]
S --> R[Репозиторий/хранилище]
C --> L[Logger: события]
C --> M[Metrics: тайминги/счётчики]
Мы измеряем время вокруг всего блока обработки команды, а не вокруг каждого шага по отдельности. Тогда тайминг отражает реальную «стоимость» команды, которую ощущает пользователь.
measureTimeMillis{ ... }: самый простой секундомер
С таймингами есть две новости: хорошая и честная. Хорошая — в Kotlin можно измерить длительность выполнения блока буквально одной функцией, и это выглядит аккуратно. Честная — измерение времени в программах не идеально (есть нагрузка системы, JIT, прогрев, фоновые процессы), поэтому мы используем миллисекунды как практичную оценку, а не как лабораторный эксперимент.
В стандартной библиотеке Kotlin есть measureTimeMillis{ ... }. Она выполняет блок и возвращает Long — сколько миллисекунд заняло выполнение. Нам этого уровня точности более чем достаточно для консольного приложения.
Мини‑пример «в вакууме»:
import kotlin.system.measureTimeMillis
fun main() {
val ms = measureTimeMillis {
var sum = 0
for (i in 1..100_000) sum += i
}
println("Took: $ms ms") // Took: <какое-то число> ms
}
Обратите внимание на стиль: мы не печатаем время внутри блока, а сначала измеряем, потом используем результат. Это дисциплина, которая потом очень пригодится: «измерили → положили в переменную → решили, что с ней делать».
Оборачиваем действие в таймер: timedResult(...)
Теперь сделаем шаг от «примерчика» к нашему проекту. Нам нужно измерять время разных действий (обработка команд), не копируя один и тот же шаблон val ms = measureTimeMillis{ ... } по всему коду. Идея простая: пишем маленькую функцию‑обёртку, которая принимает лямбду action.
Так мы получаем единый стиль: где бы ни измеряли время, код выглядит одинаково — и вы читаете программу быстрее (а ваш будущий коллега — перестаёт плакать).
Базовая версия (если нужен только тайминг):
import kotlin.system.measureTimeMillis
fun timed(action: () -> Unit): Long {
val tookMs = measureTimeMillis {
action()
}
return tookMs
}
Но часто хочется вернуть не только время, но и результат: строку для пользователя, статус выполнения и т.п. В учебном варианте можно сделать это через Pair:
import kotlin.system.measureTimeMillis
fun <T> timedResult(action: () -> T): Pair<T, Long> {
lateinit var result: T
val ms = measureTimeMillis {
result = action()
}
return result to ms
}
Да, тут используется lateinit для локальной переменной, и это выглядит чуть хитро. Но в маленькой утилите это допустимо: мы гарантируем, что action() будет вызван ровно один раз и присвоит значение.
3. Счётчики и имена метрик
Счётчики: MutableMap<String, Int> как карманная статистика
С таймингами разобрались: они отвечают «как долго». Теперь отвечаем на «как часто». Самая минимальная форма счётчиков — это MutableMap<String, Int>, где ключ — имя метрики, а значение — сколько раз событие произошло.
Мы уже умеем работать с Map и MutableMap: у карты ключи уникальны, а значение читается по ключу. Это ровно то, что нам нужно для счётчиков. Kotlin прямо подчёркивает, что Map хранит пары «ключ‑значение», а MutableMap позволяет обновлять значения по ключу.
Сделаем маленький класс Metrics, чтобы счётчики не «размазались» по всему проекту:
class Metrics {
private val counters: MutableMap<String, Int> = mutableMapOf()
fun inc(key: String) {
val prev = counters[key] ?: 0
counters[key] = prev + 1
}
fun get(key: String): Int = counters[key] ?: 0
}
В этой реализации используется паттерн «прочитал → если null, то 0 → увеличил → записал». Он же применяется повсеместно, когда вы строите счётчики по ключу в Map. Kotlin показывает, что значение по ключу читается как map["key"], а обновление можно делать как map["one"] = 11.
Имена метрик: почему "command.total" лучше, чем totalCommandCounter123
Почти все проблемы метрик в реальных проектах начинаются не с кода, а с имен. Если имена не единообразны, счётчики превращаются в свалку: addCount, AddCounter, commands_add_total, add.total — и всё это про одно и то же. Поэтому даже в учебном проекте стоит сразу привыкать к простому соглашению.
Мы выберем стиль «путь через точку»:
- "command.total" — сколько команд обработано всего
- "command.add.total" — сколько раз вызывали add
- "command.list.total" — сколько раз вызывали list
- "command.error.total" — сколько раз команда закончилась ошибкой
Это удобно тем, что ключи группируются визуально: вы сортируете строки и сразу видите «семейства». И ещё это удобно тем, что в будущем такие ключи легко превращаются в «нормальные» метрики в Prometheus/Graphite/и т.д. (сегодня мы туда не идём, но привычка останется).
4. Метрики в обработке команд
Встраиваем метрики в обработку команд
Теперь самое вкусное: добавим метрики туда, где им самое место — на уровень обработки команд. Представим упрощённый обработчик, который получает строку от пользователя, нормализует, выбирает команду и выполняет действие.
Сделаем две вещи:
- увеличиваем счётчики до/после выполнения,
- измеряем время выполнения и пишем его в лог как поле контекста.
Контекст у нас — это Map<String, String>, и мы форматируем его единообразно. Кстати, если вам нужно красиво склеить что-то из коллекции в строку, стандартная библиотека рекомендует joinToString().
Пример (очень компактный, чтобы видеть идею):
import kotlin.system.measureTimeMillis
fun handleCommand(
command: String,
logger: Logger,
metrics: Metrics,
action: () -> Unit
) {
metrics.inc("command.total")
metrics.inc("command.$command.total")
val ms = measureTimeMillis { action() }
logger.info(
message = "Command handled",
ctx = mapOf("command" to command, "tookMs" to ms.toString())
)
}
Обратите внимание: handleCommand не знает, что делает команда внутри. Это важно архитектурно: метрики — это наблюдаемость, «рамка» вокруг действия, а не часть бизнес‑логики.
Счётчики ошибок: метрика, которая спасает нервы
Ошибки мы уже логируем (со stack trace и контекстом). Но полезно ещё и считать их количество. Причина очень практичная: иногда программа не падает, а просто «часто ругается». И вы хотите увидеть это числом, не перелистывая километры логов.
Добавим инкремент метрики "command.error.total" в catch. Не будем усложнять: ловим Exception, увеличиваем счётчик, логируем ошибку.
import kotlin.system.measureTimeMillis
fun handleCommandSafe(
command: String,
logger: Logger,
metrics: Metrics,
action: () -> Unit
) {
val ms = measureTimeMillis {
try {
action()
} catch (e: Exception) {
metrics.inc("command.error.total")
logger.error("Command failed", ctx = mapOf("command" to command), e = e)
}
}
logger.info(
"Command finished",
ctx = mapOf("command" to command, "tookMs" to ms.toString())
)
}
Заметьте тонкость: здесь тайминг включает и успешный путь, и обработку ошибки. Это обычно то, что нам и нужно: мы измеряем стоимость «команда как опыт пользователя», а не только «успешную ветку».
5. Отчёт по метрикам и работа с Map
Мини‑отчёт по метрикам: печатаем по команде metrics
Очень хочется в конце каждого действия печатать «метрики сейчас такие-то». Но мы помним, что лишний вывод превращается в шум. В учебном консольном приложении хороший компромисс — сделать отдельную команду, например metrics, которая печатает текущие значения счётчиков.
Для этого нам понадобится получить «снимок» карты счётчиков. Вернём read‑only Map, чтобы внешний код случайно не сломал внутреннее состояние.
class Metrics {
private val counters: MutableMap<String, Int> = mutableMapOf()
fun inc(key: String) {
val prev = counters[key] ?: 0
counters[key] = prev + 1
}
fun snapshot(): Map<String, Int> = counters.toMap()
}
Дальше превращаем Map в текст. Мы можем пройти по entries и склеить строки через joinToString(), который как раз предназначен для «сборки читаемой строки из элементов коллекции».
fun formatMetrics(metrics: Metrics): String {
val snap = metrics.snapshot()
return snap.entries
.sortedBy { it.key }
.joinToString(separator = "\n") { (k, v) -> "$k = $v" }
}
И где-то в CLI:
fun printMetrics(metrics: Metrics) {
println(formatMetrics(metrics))
// command.add.total = 2
// command.error.total = 1
// command.total = 3
}
Здесь println — это именно пользовательский вывод (по команде пользователя). Логи при этом продолжают жить своей жизнью.
Нюанс: Map — не Collection
Когда вы активно используете списки, возникает ощущение, что «все структуры данных одинаковые». Но Map устроена иначе: у неё нет «элементов без ключей», она хранит записи (entries). Kotlin отдельно подчёркивает, что Map<K, V> — это отдельный вид коллекции и предоставляет специфичные операции вроде доступа к значениям по ключу и работы с ключами/значениями.
Почему это важно для метрик? Потому что метрики по смыслу почти всегда «ключ → значение». Нам не нужен List<Int>, где непонятно, что означает 17‑й элемент. Нам нужен Map<String, Int>, где смысл встроен в ключ: "command.add.total".
6. Типичные ошибки
Ошибка №1: измерять «всё подряд», включая внутренности циклов.
Когда тайминг появляется в каждой функции и вокруг каждого маленького участка кода, вы получаете море цифр без ответа на вопрос «а что, собственно, медленно?». В консольном приложении почти всегда достаточно измерять границы операции: обработку одной команды, построение одного отчёта, выполнение одного сценария.
Ошибка №2: смешивать метрики с бизнес‑логикой так, что без метрик ничего не работает.
Метрики — это наблюдаемость, а не функциональность. Если вы написали код так, что «сначала посчитаем счётчик, иначе команда не выполнится», вы случайно сделали счётчик частью бизнес‑инварианта. Правильнее держать метрики как рамку: они не должны влиять на корректность результата.
Ошибка №3: хаотичные имена ключей в счётчиках.
Сегодня вы пишете addCount, завтра AddCount, послезавтра "command.add.total", и потом удивляетесь, что «статистика не сходится». Фиксируйте формат ключей заранее (например, "command.add.total") и придерживайтесь его. Это скучно, но скука — один из признаков хорошей инженерии.
Ошибка №4: превращать метрики в лог‑спам.
Если на каждую команду печатать пять строчек «текущее значение счётчиков», это очень быстро убивает читаемость. Метрики либо пишутся в контекст логов дозировано (например, tookMs), либо выводятся по отдельной команде (metrics). Если вы не можете быстро глазами найти важные сообщения, значит вы уже проиграли битву с шумом.
Ошибка №5: «верить миллисекундам как судьбе».
Тайминги в миллисекундах полезны, но они зависят от нагрузки системы и могут колебаться. Если один запуск показал 2 мс, а другой 9 мс — это ещё не повод переписывать всё на ассемблер и уходить в горы. Смотрите на тенденции и на крупные значения, а не на «микро‑шумы».
ПЕРЕЙДИТЕ В ПОЛНУЮ ВЕРСИЮ