1. Introduction
When you’re just starting to write programs, it can seem like logs are diagnostics. “I’ll print more text—and I’ll understand everything.” A couple of weeks of reality later, it turns out that “more text” becomes “more noise,” and the answer to “why is the program slow?” is extracted from logs roughly like archaeology: with a brush, and with tears.
Metrics are a different kind of observability. If logs tell stories (sometimes dramatic ones), metrics are dry statistics. Roughly: logs answer “what happened with this command,” while metrics answer “how many such commands happened during the lifetime of the program, and how much time they took.”
It helps to keep a simple table in mind:
| What we observe | Logs | Metrics |
|---|---|---|
| Meaning | “Events” | “Measurements” |
| Typical question | “What went wrong?” | “How often?” / “How long?” |
| Example | |
|
| Risk | too much noise | too many numbers without meaning |
And an important practical point: metrics do not replace logs. They complement them, like a thermometer complements the complaint “I feel bad.” A single number can’t tell the whole story, but it can quickly show that “temperature 39” is no longer “meh, just a bit tired.”
2. Timings in a console application
Where to use timings in a console application
At the beginning it’s easy to go to an extreme: start measuring the time of every function, every if, and every glance at a variable. That’s not metrics—that’s anxiety written into code. In a console application, timings are useful on operation boundaries, i.e., where the user actually initiated an action: handling a command, building a report, import/export, computing statistics.
To make this concrete, we’ll continue our learning CLI project (let’s call it ExpenseTracker). In it, the user enters commands like add, list, remove, total. Our logs already have levels, context, and error printing. Now we want to measure, for example, how long handling each command takes and how often commands are called.
The process diagram looks roughly like this:
flowchart LR
U[User enters a command] --> C[CLI: parse/dispatch]
C --> S[Scenario/service]
S --> R[Repository/storage]
C --> L[Logger: events]
C --> M[Metrics: timings/counters]
We measure time around the entire command handling block, not around each step separately. Then the timing reflects the real “cost” of the command as perceived by the user.
measureTimeMillis{ ... }: the simplest stopwatch
With timings there are two pieces of news: good and honest. The good one: in Kotlin you can measure a block’s execution duration with literally one function, and it looks neat. The honest one: time measurement in programs is not perfect (system load, JIT, warm-up, background processes), so we use milliseconds as a practical estimate, not as a lab experiment.
Kotlin’s standard library has measureTimeMillis{ ... }. It runs the block and returns a Long—how many milliseconds execution took. That level of precision is more than enough for a console application.
A mini example “in a vacuum”:
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: <some number> ms
}
Note the style: we don’t print the time inside the block; we measure first, then use the result. This is a discipline that will help a lot later: “measured → stored in a variable → decided what to do with it.”
Wrapping an action in a timer: timedResult(...)
Now let’s move from a “tiny example” to our project. We need to measure the time of different actions (command handling) without copying the same template val ms = measureTimeMillis{ ... } across the codebase. The idea is simple: write a small wrapper function that takes a lambda action.
This gives us a unified style: wherever we measure time, the code looks the same—and you read the program faster (and your future coworker stops crying).
Basic version (if you only need the timing):
import kotlin.system.measureTimeMillis
fun timed(action: () -> Unit): Long {
val tookMs = measureTimeMillis {
action()
}
return tookMs
}
But often you want to return not just time, but also the result: a string for the user, an execution status, etc. In a learning version, you can do this via 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
}
Yes, this uses lateinit for a local variable, and it looks a bit tricky. But in a small utility it’s acceptable: we guarantee that action() will be called exactly once and will assign a value.
3. Counters and metric names
Counters: MutableMap<String, Int> as pocket statistics
Timings are clear: they answer “how long.” Now we answer “how often.” The most minimal form of counters is a MutableMap<String, Int>, where the key is the metric name and the value is how many times the event happened.
We already know how to work with Map and MutableMap: keys in a map are unique, and the value is read by key. That’s exactly what we need for counters. Kotlin explicitly emphasizes that Map stores “key-value” pairs, and MutableMap lets you update values by key.
Let’s make a small Metrics class so counters don’t get “smeared” all over the project:
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
}
This implementation uses the pattern “read → if null then 0 → increment → write.” It’s used everywhere when you build per-key counters in a Map. Kotlin shows that a value by key is read as map["key"], and updates can be done like map["one"] = 11.
Metric names: why "command.total" is better than totalCommandCounter123
Almost all real-world metric problems start not with code, but with names. If names are inconsistent, counters turn into a junk pile: addCount, AddCounter, commands_add_total, add.total—and all of that is about the same thing. So even in a learning project, it’s worth getting used to a simple convention right away.
We’ll choose the “dot-separated path” style:
- "command.total" — how many commands were processed in total
- "command.add.total" — how many times add was called
- "command.list.total" — how many times list was called
- "command.error.total" — how many times a command ended with an error
This is convenient because keys group visually: you sort strings and immediately see “families.” It’s also convenient because in the future such keys easily turn into “real” metrics in Prometheus/Graphite/etc. (we’re not going there today, but the habit will stick).
4. Metrics in command handling
Embedding metrics into command handling
Now the best part: let’s add metrics where they belong—at the command handling level. Imagine a simplified handler that receives a string from the user, normalizes it, selects the command, and executes the action.
We’ll do two things:
- increment counters before/after execution,
- measure execution time and write it to the log as a context field.
Our context is a Map<String, String>, and we format it consistently. By the way, if you need to nicely glue something from a collection into a string, the standard library recommends joinToString().
Example (very compact, so you can see the idea):
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())
)
}
Note: handleCommand doesn’t know what the command does internally. This is architecturally important: metrics are observability, a “frame” around an action, not part of the business logic.
Error counters: the metric that saves your nerves
We already log errors (with stack trace and context). But it’s also useful to count them. The reason is very practical: sometimes the program doesn’t crash; it just “complains often.” And you want to see that as a number, without scrolling through kilometers of logs.
Let’s add an increment for "command.error.total" in catch. We won’t complicate it: catch Exception, increment the counter, log the error.
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())
)
}
Notice a subtle point: here the timing includes both the successful path and error handling. This is usually what we want: we measure the cost of “the command as a user experience,” not only “the successful branch.”
5. Metrics report and working with Map
Mini metrics report: print on the metrics command
It’s very tempting to print “the metrics are currently X” at the end of every action. But we remember that extra output turns into noise. In a learning console application, a good compromise is to make a separate command, for example metrics, which prints the current counter values.
For that, we need to get a “snapshot” of the counter map. We’ll return a read-only Map so external code can’t accidentally break internal state.
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()
}
Next, turn the Map into text. We can iterate over entries and glue lines with joinToString(), which is designed specifically for “building a readable string from collection elements.”
fun formatMetrics(metrics: Metrics): String {
val snap = metrics.snapshot()
return snap.entries
.sortedBy { it.key }
.joinToString(separator = "\n") { (k, v) -> "$k = $v" }
}
And somewhere in the CLI:
fun printMetrics(metrics: Metrics) {
println(formatMetrics(metrics))
// command.add.total = 2
// command.error.total = 1
// command.total = 3
}
Here println is user-facing output (on the user’s command). Logs continue to live their own life.
Nuance: Map is not a Collection
When you actively use lists, it can feel like “all data structures are the same.” But Map is different: it has no “elements without keys”; it stores records (entries). Kotlin emphasizes separately that Map<K, V> is a distinct kind of collection and provides specific operations like accessing values by key and working with keys/values.
Why does this matter for metrics? Because metrics are almost always “key → value” by meaning. We don’t need a List<Int> where it’s unclear what the 17th element means. We need a Map<String, Int> where the meaning is built into the key: "command.add.total".
6. Common mistakes
Mistake No. 1: measuring “everything,” including loop internals.
When timing appears in every function and around every tiny piece of code, you get a sea of numbers without an answer to “so what, exactly, is slow?” In a console application it’s almost always enough to measure operation boundaries: handling one command, building one report, running one scenario.
Mistake No. 2: mixing metrics into business logic so that nothing works without metrics.
Metrics are observability, not functionality. If you write code like “first increment the counter, otherwise the command won’t execute,” you’ve accidentally made the counter part of a business invariant. It’s better to keep metrics as a frame: they must not affect result correctness.
Mistake No. 3: chaotic key names in counters.
Today you write addCount, tomorrow AddCount, the day after tomorrow "command.add.total", and then you’re surprised that “the stats don’t add up.” Lock down the key format in advance (for example, "command.add.total") and stick to it. It’s boring, but boredom is one of the signs of good engineering.
Mistake No. 4: turning metrics into log spam.
If you print five lines of “current counter values” for every command, it very quickly kills readability. Metrics are either written into log context sparingly (for example, tookMs), or printed via a separate command (metrics). If you can’t quickly find important messages with your eyes, you’ve already lost the battle against noise.
Mistake No. 5: “believing milliseconds as fate.”
Millisecond timings are useful, but they depend on system load and can fluctuate. If one run shows 2 ms and another shows 9 ms, that’s not yet a reason to rewrite everything in assembly and move to the mountains. Look at trends and large values, not micro-noise.
GO TO FULL VERSION