paulserban.eu

Writing Edition

Paul Serban

Writing, snippets & book notes

July 15, 2023

Structured Logging for Dockerized Node.js Services: Pino, OpenTelemetry Collector, ClickHouse, and Grafana

A step-by-step walkthrough for building a production-grade logging pipeline for Express.js - plus dashboard best practices

Introduction

Most Node.js teams start their logging journey with console.log, then graduate to a logging library like pino once they need levels, timestamps, and JSON output. That upgrade solves the "how do we produce logs" problem, but it leaves the harder question unanswered: how do those logs get from a container running somewhere in a cluster into a place where an engineer can actually search, correlate, and alert on them during an incident. This is the gap that an observability pipeline built on the OpenTelemetry Collector, ClickHouse, and Grafana is designed to close.

This walkthrough builds that pipeline end to end. We will instrument an Express.js service with pino so it emits structured JSON logs, ship those logs over OTLP to an OpenTelemetry Collector, write them into ClickHouse using the Collector's ClickHouse exporter, and query them from Grafana using the official ClickHouse data source plugin. Along the way we will cover the reasoning behind each component choice, a working Docker Compose setup, and a set of best practices for building logging dashboards that stay useful once the volume of log lines moves from thousands to billions.

Context and Problem Overview

Logging pipelines tend to accrete complexity in the same order every time. First, an application logs freeform strings to stdout. Then someone adds a log shipper - Filebeat, Fluent Bit, or a vendor agent - that tails container logs and forwards them to an aggregator like Elasticsearch or a SaaS product. This works, but it usually means the application, the transport format, and the storage backend are all coupled through ad hoc parsing rules, regexes that break when a message changes, and a schema that only exists implicitly in dashboards. The OpenTelemetry project exists specifically to standardize this middle layer so that instrumentation, transport, and backend can evolve independently.

Choosing ClickHouse as the storage layer is a deliberate trade-off rather than a default. ClickHouse is a column-oriented OLAP database originally built at Yandex, and it is exceptionally good at ingesting high-volume, append-only, semi-structured event data and running aggregate queries over it - exactly the access pattern that log analytics requires: "count errors by service over the last hour", "show me the p95 request duration bucketed by minute", "find all logs with this trace ID". It is also dramatically cheaper to operate at scale than a general-purpose search engine like Elasticsearch when the primary use case is time-bounded filtering and aggregation rather than full-text relevance ranking, which is why it has become a common backend choice for logging and observability platforms (including some commercial ones built directly on top of it).

Grafana completes the loop as the query and visualization layer. Since Grafana added Logs as a first-class panel type alongside Metrics and Traces, and since the community and Grafana Labs have both invested in ClickHouse connectivity, it has become practical to run all three observability pillars - logs, metrics, and traces - through a single pane of glass without adopting a full commercial stack. The architecture in this article reflects a pattern increasingly used by teams who want OpenTelemetry-native instrumentation without being locked into a specific vendor's ingestion format.

Architecture Deep Dive

The pipeline has four moving parts, each running as its own container so the setup mirrors what you would deploy in a real environment. The Express application uses pino as its logger and a pino transport that speaks the OpenTelemetry Logs protocol (OTLP), so log records leave the process already carrying trace context, resource attributes like service.name, and a well-defined severity number rather than an arbitrary string. The OpenTelemetry Collector receives those records on its OTLP receiver, and this is the layer where you enrich, filter, and route telemetry: adding a deployment.environment attribute, dropping debug-level noise before it hits storage, or fanning the same data out to multiple backends without touching application code.

From the Collector, log records are written into ClickHouse using the clickhouseexporter component from the OpenTelemetry Collector Contrib distribution. This exporter manages table creation and inserts using ClickHouse's native protocol, batching writes for throughput, which matters because ClickHouse strongly prefers large, infrequent inserts over many small ones. Grafana then connects to ClickHouse through the grafana-clickhouse-datasource plugin, which understands ClickHouse's SQL dialect well enough to support the Logs panel, ad hoc filters, and template variables. The important architectural property here is that nothing in this chain is proprietary: OTLP, the Collector, and the ClickHouse wire protocol are all open specifications or open-source implementations, so any piece can be swapped later - a different backend, a different frontend, a different language SDK - without rewriting the others.

Step-by-Step Implementation

Instrumenting the Express service with Pino

Start with a standard Express application and add pino along with pino-http for automatic request/response logging, and pino-opentelemetry-transport, a transport maintained under the pino GitHub organization that converts pino's log objects into OTLP log records and ships them to a collector endpoint. The transport approach is preferable to tailing log files inside the container because it avoids needing a sidecar or a filesystem mount just to get logs out, which keeps the container's runtime footprint minimal and matches how you would typically deploy to Kubernetes or ECS.

// logger.ts
import pino from "pino";

export const logger = pino({
  level: process.env.LOG_LEVEL ?? "info",
  transport: {
    target: "pino-opentelemetry-transport",
    options: {
      resourceAttributes: {
        "service.name": process.env.SERVICE_NAME ?? "orders-api",
        "service.version": process.env.SERVICE_VERSION ?? "0.0.0",
        "deployment.environment": process.env.NODE_ENV ?? "development",
      },
      // Collector's OTLP/gRPC log endpoint, resolved via Docker DNS
      endpoint: process.env.OTEL_EXPORTER_OTLP_ENDPOINT
        ?? "http://otel-collector:4317",
    },
  },
});
// app.ts
import express from "express";
import pinoHttp from "pino-http";
import { randomUUID } from "node:crypto";
import { logger } from "./logger";

const app = express();

app.use(
  pinoHttp({
    logger,
    genReqId: (req) => req.headers["x-request-id"]?.toString() ?? randomUUID(),
    customProps: (req) => ({
      // Attributes here become structured fields, not string concatenation
      route: req.route?.path,
    }),
  })
);

app.get("/orders/:id", async (req, res) => {
  req.log.info({ orderId: req.params.id }, "fetching order");
  try {
    const order = await lookupOrder(req.params.id);
    if (!order) {
      req.log.warn({ orderId: req.params.id }, "order not found");
      return res.status(404).json({ error: "not_found" });
    }
    res.json(order);
  } catch (err) {
    req.log.error({ err, orderId: req.params.id }, "failed to fetch order");
    res.status(500).json({ error: "internal_error" });
  }
});

app.listen(3000, () => logger.info("orders-api listening on :3000"));

Notice that every call passes structured fields as the first argument rather than interpolating values into the message string. This single habit is what makes the rest of the pipeline valuable - a message like "fetching order" with a separate orderId field is filterable and aggregable in ClickHouse, while `fetching order ${id}` is not, no matter how good the downstream tooling is.

Dockerizing the service and the supporting stack

The application container itself needs nothing special for logging beyond the environment variables above, since the transport talks to the Collector over the network rather than writing to a file or stdout. The rest of the stack is defined in Docker Compose so the whole pipeline comes up with one command.

# docker-compose.yml
version: "3.9"
services:
  orders-api:
    build: .
    environment:
      SERVICE_NAME: orders-api
      NODE_ENV: production
      OTEL_EXPORTER_OTLP_ENDPOINT: http://otel-collector:4317
    ports:
      - "3000:3000"
    depends_on:
      - otel-collector

  otel-collector:
    image: otel/opentelemetry-collector-contrib:0.105.0
    command: ["--config=/etc/otel-collector-config.yaml"]
    volumes:
      - ./otel-collector-config.yaml:/etc/otel-collector-config.yaml
    ports:
      - "4317:4317" # OTLP gRPC
    depends_on:
      - clickhouse

  clickhouse:
    image: clickhouse/clickhouse-server:24.8
    ports:
      - "8123:8123" # HTTP interface
      - "9000:9000" # native protocol
    volumes:
      - clickhouse-data:/var/lib/clickhouse

  grafana:
    image: grafana/grafana:11.1.0
    ports:
      - "3001:3000"
    environment:
      GF_INSTALL_PLUGINS: grafana-clickhouse-datasource
    depends_on:
      - clickhouse

volumes:
  clickhouse-data:

Configuring the OpenTelemetry Collector

The Collector configuration wires the OTLP receiver to the ClickHouse exporter through a small processing chain. The batch processor is not optional in any real deployment - without it, the exporter would issue one ClickHouse insert per log record, which will not scale and works against how ClickHouse expects to be written to. The resource processor is where you would normalize or add cluster-wide attributes such as cloud.region that the application itself doesn't know about.

# otel-collector-config.yaml
receivers:
  otlp:
    protocols:
      grpc:
        endpoint: 0.0.0.0:4317

processors:
  batch:
    timeout: 5s
    send_batch_size: 10000
  resource:
    attributes:
      - key: cluster.name
        value: local-dev
        action: upsert

exporters:
  clickhouse:
    endpoint: tcp://clickhouse:9000?dial_timeout=10s
    database: otel
    logs_table_name: otel_logs
    ttl: 720h # 30-day retention, enforced by ClickHouse TTL
    create_schema: true

service:
  pipelines:
    logs:
      receivers: [otlp]
      processors: [resource, batch]
      exporters: [clickhouse]

With create_schema: true, the exporter creates a MergeTree-family table on first startup with columns for timestamp, severity, body, trace and span IDs, and resource/log attributes stored as Map(String, String) columns - a schema shape that works well for the mixed, evolving attribute sets that structured logs tend to have. In a production environment you would typically manage this DDL explicitly rather than relying on auto-creation, so that partitioning, ordering keys, and TTL are under version control alongside the rest of your infrastructure.

Building the Grafana Dashboard

Once logs are flowing into ClickHouse, add it as a data source in Grafana using the grafana-clickhouse-datasource plugin, pointing it at clickhouse:9000 with the otel database. The plugin auto-detects the OTel logs schema convention and lets you use the built-in Logs panel type directly, which renders records in the familiar scrolling log-line format with severity color coding and expandable structured fields, rather than forcing you to hand-write every query as a table.

For anything beyond the default Explore view, you will write ClickHouse SQL directly in panel queries. A panel showing error volume per service over time might look like this:

SELECT
  toStartOfMinute(Timestamp) AS time,
  ResourceAttributes['service.name'] AS service,
  count() AS error_count
FROM otel.otel_logs
WHERE SeverityText IN ('error', 'fatal')
  AND Timestamp BETWEEN $__fromTime AND $__toTime
GROUP BY time, service
ORDER BY time

$__fromTime and $__toTime are Grafana macros substituted with the dashboard's active time range, which is what lets the same query drive both a live dashboard and an ad hoc Explore investigation. A companion panel for tracing a single request across the system might filter on TraceId = '$trace_id', where $trace_id is a dashboard template variable - this is the query pattern that lets an engineer click from a slow trace span directly into the exact log lines emitted during that request, provided the application propagates trace context into its logs, which the OTLP transport does automatically by reading the active OpenTelemetry context.

Dashboards built this way should be organized around questions, not around data sources. A "Service Health" dashboard with panels for error rate, latency percentiles, and a filtered log stream answers "is this service healthy right now", while a separate "Deployment" dashboard annotated with release markers answers "did the last deploy cause this". Mixing every possible metric and log query onto one dashboard produces something nobody opens during an incident because it takes too long to find the signal.

Essential Logging Panels and Alerting Patterns

The generic "error rate over time" panel shown above is a reasonable starting point, but a dashboard that is actually useful during an incident needs a small, deliberate set of panels that answer specific questions in a specific order: is something wrong right now, has it been getting worse, and which part of the system is responsible. The four patterns below cover that progression, and they are worth building as a standard template that every service's dashboard inherits, rather than reinventing per team.

Aggregated Error Rate Panel

The first panel an on-call engineer should see is a single, unambiguous number: what fraction of requests or operations are currently failing. This is best rendered as a Stat or Gauge panel showing an error rate percentage over a short rolling window (five to fifteen minutes), with thresholds that shift the panel's color from green to amber to red. Because the OTLP logs table already carries SeverityText per record, the simplest version of this panel counts error-level log lines as a proportion of total request logs, though a more precise version joins against a request-count signal (from pino-http's completion logs or a separate metrics pipeline) so that the denominator reflects actual traffic rather than log volume, which can be skewed by retries or verbose non-request logging.

SELECT
  countIf(SeverityText IN ('error', 'fatal')) AS error_count,
  count() AS total_count,
  round(error_count / total_count * 100, 2) AS error_rate_pct
FROM otel.otel_logs
WHERE ResourceAttributes['service.name'] = '$service'
  AND Timestamp BETWEEN $__fromTime AND $__toTime

Error Rate Over Time by Reason

A single aggregated number tells you that something is wrong; a breakdown over time tells you what and since when. This panel is a stacked or multi-series time series chart, grouped by an error reason attribute - typically the error.type, an application-defined reason field, or the HTTP status code bucket - so that a spike is immediately attributable rather than requiring a follow-up query. This is also where the discipline of structured logging pays for itself directly: an error log written as req.log.error({ err, orderId }, "failed to fetch order") should also carry a stable, low-cardinality err.type or err.code field (for example, DATABASE_TIMEOUT or VALIDATION_FAILED) precisely so this panel can group by something more useful than the free-text message, which varies too much between call sites to aggregate cleanly.

SELECT
  toStartOfMinute(Timestamp) AS time,
  LogAttributes['err.type'] AS reason,
  count() AS error_count
FROM otel.otel_logs
WHERE ResourceAttributes['service.name'] = '$service'
  AND SeverityText IN ('error', 'fatal')
  AND Timestamp BETWEEN $__fromTime AND $__toTime
GROUP BY time, reason
ORDER BY time

Top-N Table of Failing Endpoints or Operations

Once the dashboard shows that errors are rising and roughly why, the next question is where - which route, queue consumer, or downstream dependency is generating the bulk of the failures. A Table panel ranking the top offenders over the selected time window answers this without forcing the engineer to pivot into Explore and write an ad hoc query mid-incident. This pattern generalizes well beyond HTTP routes: the same shape of query works for background job names, external API hosts, or database table names, as long as that dimension was captured as a structured attribute at log time rather than buried in a message string.

SELECT
  LogAttributes['route'] AS route,
  LogAttributes['err.type'] AS reason,
  count() AS failures
FROM otel.otel_logs
WHERE ResourceAttributes['service.name'] = '$service'
  AND SeverityText IN ('error', 'fatal')
  AND Timestamp BETWEEN $__fromTime AND $__toTime
GROUP BY route, reason
ORDER BY failures DESC
LIMIT 10

Alerting on the Same Signals the Dashboard Shows

Alert rules should never be invented separately from dashboards; they should be built as a direct extension of the panels described above. Grafana's alerting engine lets you attach an alert rule to an existing panel through the panel's own menu, which evaluates the same query on a schedule and fires when a threshold is breached - meaning the aggregated error rate panel and the "error rate exceeds 5% for five minutes" alert rule should, ideally, be the same query with a condition added, not two independently maintained pieces of logic that can silently drift apart over time. When an alert is created this way, Grafana automatically records __dashboardUid__ and __panelId__ annotations on the rule, and these are what power the "View panel" link that appears both in Grafana's alert list UI and in notification templates sent to Slack, PagerDuty, or email.

This link is the detail that most teams skip and later regret. An alert that says "orders-api error rate is 12%" is a starting point; an alert that also carries a direct link to the panel - pre-filtered to the same service, time range, and label set that triggered it - turns a page into an investigation that starts already scoped correctly. As a working rule, every alert rule in the system should have a corresponding panel, on a dashboard the responding engineer already knows how to find, that visualizes the exact signal the alert evaluates over time; if a new alert is added without a panel to back it, that is a sign the alert was defined ad hoc rather than derived from an existing, understood metric, and it is worth pausing to build the panel first.

Trade-offs and Pitfalls

This architecture is not free, and it is worth being honest about where the cost shows up. Running your own ClickHouse cluster means you are responsible for its operational concerns: disk sizing, replication if you need high availability, and monitoring the monitoring system itself. ClickHouse is efficient, but a busy fleet of services logging at info level in production can still produce terabytes of data per month, and without deliberate retention (TTL) and sampling policies, storage costs and query latency both degrade quietly until someone notices a dashboard has gotten slow. Compare this against a managed logging SaaS, where you trade ongoing infrastructure ownership for a recurring bill that scales with volume - the self-hosted approach usually wins on cost at scale but loses on time-to-value early on, since someone has to build and maintain the pipeline described in this article.

The other common pitfall is attribute cardinality. It is tempting to attach highly unique values - a full user ID, a raw request body, a UUID per line - as attributes because pino makes it so easy to pass structured fields. In ClickHouse this is less catastrophic than in a system like Prometheus, where high-cardinality labels can blow up the index, but it still inflates storage and slows down GROUP BY queries on the Map-typed attribute columns, and it can leak sensitive data into a system that most engineers assume is safe to query freely. A related trap is over-instrumenting at debug level in production: without a level filter in the Collector or the application, verbose debug logging can dominate both cost and signal-to-noise ratio during exactly the high-traffic periods when you most need clarity. Finally, teams sometimes skip defining the ClickHouse table schema explicitly and let the exporter's auto-created schema drift silently across collector versions, which then breaks dashboards after a routine upgrade with no clear error message pointing at the cause.

Best Practices for Logging Dashboards in Grafana

Treat log level as a first-class dimension, not decoration. Pino encodes severity as a number (10 trace, 20 debug, 30 info, 40 warn, 50 error, 60 fatal), and OTLP has an equivalent SeverityNumber field; use that numeric field for filtering and thresholds rather than string-matching SeverityText, since numeric comparisons are cheaper for ClickHouse to execute and are immune to casing or naming inconsistencies across services written by different teams. Color severity consistently across every dashboard in your organization - reserving red strictly for error/fatal - so that an on-call engineer jumping between dashboards during an incident doesn't have to relearn a color scheme under pressure.

Correlate logs with traces and metrics rather than building logs-only dashboards for anything beyond simple debugging. The value of propagating trace_id and span_id into every log line, as this pipeline does automatically, is that a latency spike found in a metrics panel can be explained by clicking through to the exact log lines for the slow trace, rather than guessing at a time range and hoping the right log line is in it. Grafana's data link feature can wire this up directly: a field configuration on a metrics panel that constructs a link to the Logs data source, pre-filled with the relevant trace_id, turns three separate investigations into one click.

Design for the incident, not the demo. A dashboard that looks impressive with twenty panels is usually worse under pressure than one with four: request rate, error rate, latency percentiles, and a log panel pre-filtered to severity >= error. Use template variables for service, environment, and deployment.environment so the same dashboard serves every service in your fleet instead of maintaining a near-duplicate dashboard per team, and set a sensible default time range - six hours is a reasonable default for most services - so a panel doesn't silently load a query over 30 days of raw log data and time out. Finally, alert on the log-derived metrics that indicate real user impact, such as a sustained increase in the rate of error-level logs per service, rather than alerting on log volume alone, which tends to fire on entirely benign events like a deploy that temporarily doubles startup-log verbosity.

Key Takeaways

For teams ready to build this pipeline, the following steps translate directly into action:

  1. Log structured fields, not interpolated strings - pass an object as pino's first argument so every value stays queryable downstream.
  2. Ship logs over OTLP using a transport like pino-opentelemetry-transport instead of tailing files, which removes a moving part from your container.
  3. Let the OpenTelemetry Collector own enrichment and batching, so application code stays free of backend-specific logic and infrastructure attributes are added in one place.
  4. Define your ClickHouse log table schema explicitly, with a partitioning key on date and a TTL clause, rather than depending on exporter auto-creation in production.
  5. Build Grafana dashboards around incident questions with trace-to-log data links, not around an exhaustive list of every metric you can query.

Conclusion

The pipeline described here - pino to OTLP, the OpenTelemetry Collector as the routing and enrichment layer, ClickHouse as the storage engine, and Grafana as the query surface - is not the only valid way to build observability for a Node.js service, but it demonstrates a pattern that has become increasingly common precisely because every layer is replaceable. You can swap ClickHouse for a different OTLP-compatible backend, swap Grafana for another frontend, or add metrics and traces to the same Collector pipeline without touching the application's instrumentation, because OpenTelemetry was designed from the start to decouple what you instrument from where the data ends up.

What ultimately makes a logging system useful during an incident is not the sophistication of the pipeline but the discipline applied at the point of instrumentation: structured fields instead of string concatenation, consistent severity semantics, and trace correlation baked in from the first log line. The infrastructure in this article exists to get out of the way of that discipline - to make sure that once an engineer writes logger.error({ orderId, err }, "failed to fetch order"), that log line reliably ends up somewhere searchable, correlated, and fast to query, without anyone having to think about the plumbing again.

References