Post 12 of 15 | Phase 8: Observability
Logging, Metrics, and Tracing — Understanding What Is Happening Inside Your App
You have built a working microservices backend. Services are communicating, data is persisting to MongoDB, authentication is working. Now comes the question that every developer faces in production: when something goes wrong, how do you find out what happened and where?
In a monolith you add a console.log and check one log file. In microservices you have ten services running, each producing its own logs, handling hundreds of requests per second. You need proper tools to make sense of it all.
Observability has three pillars:
- Logging — what happened and when
- Metrics — how is the system performing right now
- Tracing — how did a specific request travel through the system
Moleculer has built-in support for all three.
Pillar 1: Logging
You have been using this.logger throughout the course. Let us now understand logging properly and set it up for real use.
Log Levels
Moleculer has six log levels in order from most to least verbose:
trace — extremely detailed, every internal step
debug — debugging information, variable values
info — normal operational messages, service started, action called
warn — something unexpected happened but the app is still running
error — something failed, needs attention
fatal — critical failure, app may not recover
In development use info or debug. In production use warn or error to reduce noise and storage cost.
Configuring the Logger in moleculer.config.js
module.exports = {
logger: {
type: "Console",
options: {
// Show colors in terminal output
colors: true,
// Different colors for different services
moduleColors: true,
// full shows timestamp, level, nodeID, service name, message
// short shows less information
// simple shows just level and message
// json outputs machine-readable JSON — use in production
formatter: "full",
// Automatically pad service names so logs align in columns
autoPadding: true
}
},
logLevel: "info"
};
Using the Logger in Services
module.exports = {
name: "order",
actions: {
async create(ctx) {
// Different log levels for different situations
this.logger.debug("create action called", ctx.params);
this.logger.info(`Creating order for user ${ctx.meta.user.id}`);
try {
const order = await this.adapter.insert(ctx.params);
this.logger.info(`Order created successfully: ${order._id}`);
return order;
} catch (err) {
this.logger.error("Failed to create order", err);
throw err;
}
}
}
};
Multiple Loggers at Once
In production you often want logs to go to both the console and a file or external service. Moleculer supports multiple loggers simultaneously:
module.exports = {
logger: [
// Console logger for development visibility
{
type: "Console",
options: {
formatter: "short",
colors: true
}
},
// File logger — writes to a file
{
type: "File",
options: {
// Log file location
filename: "logs/moleculer-{date}.log",
// New file every day
eol: "\n",
// Format as JSON for log parsing tools
formatter: "json"
}
}
],
logLevel: {
// Different levels for different services
// "*" is the default for all services
"*": "warn",
// Show more detail for the order service
"ORDER": "debug",
// Show all logs from the broker itself
"BROKER": "info"
}
};
Structured Logging — Logging Objects Not Strings
In production, logs are parsed by tools like Datadog, Elasticsearch, or CloudWatch. These tools work best with structured JSON logs. Always log objects alongside messages instead of concatenating strings:
// Bad — hard to parse programmatically
this.logger.info("Order " + orderId + " created for user " + userId + " with total " + total);
// Good — structured, easy to parse and filter
this.logger.info("Order created", {
orderId,
userId,
total,
productId,
timestamp: new Date().toISOString()
});
Pillar 2: Metrics
Metrics tell you how your system is performing right now. Things like:
- How many requests per second is each service handling
- What is the average response time of each action
- How many errors are occurring
- How much memory is being used
- How many active connections exist
Moleculer has a built-in metrics system that can expose these numbers to external monitoring tools like Prometheus and Grafana.
Enabling Metrics in moleculer.config.js
module.exports = {
metrics: {
enabled: true,
// Where to send metrics
reporter: [
// Console reporter — prints metrics to terminal periodically
{
type: "Console",
options: {
// Print metrics every 10 seconds
interval: 10
}
},
// Prometheus reporter — exposes metrics at an HTTP endpoint
// Grafana reads from Prometheus to create dashboards
{
type: "Prometheus",
options: {
// Metrics available at http://localhost:3030/metrics
port: 3030,
path: "/metrics",
// Default labels added to every metric
defaultLabels: (registry) => ({
namespace: registry.broker.namespace,
nodeID: registry.broker.nodeID
})
}
}
]
}
};
Install the Prometheus reporter:
npm install @moleculer/lab
Actually for Prometheus you need:
npm install moleculer-prometheus
When Prometheus metrics are enabled, visit http://localhost:3030/metrics and you will see output like this:
# HELP moleculer_request_total Total count of requests
# TYPE moleculer_request_total counter
moleculer_request_total{action="user.login",nodeID="node-1"} 42
# HELP moleculer_request_time_milliseconds Request time in milliseconds
# TYPE moleculer_request_time_milliseconds histogram
moleculer_request_time_milliseconds_bucket{action="user.login",le="10"} 38
moleculer_request_time_milliseconds_bucket{action="user.login",le="100"} 42
# HELP moleculer_request_error_total Total count of request errors
# TYPE moleculer_request_error_total counter
moleculer_request_error_total{action="user.login",nodeID="node-1"} 2
Prometheus scrapes this endpoint periodically and stores the data. Grafana connects to Prometheus and displays it as beautiful dashboards.
Built-in Metrics Moleculer Tracks Automatically
When metrics are enabled, Moleculer automatically tracks these without any code from you:
moleculer.request.total — total requests per action
moleculer.request.active — currently processing requests
moleculer.request.error.total — total errors per action
moleculer.request.time — response time histogram per action
moleculer.event.total — total events emitted
moleculer.transporter.sent.total — messages sent via transporter
moleculer.process.memory.heap — Node.js heap memory usage
moleculer.process.cpu — CPU usage percentage
moleculer.os.memory.free — free system memory
All of this is tracked automatically. Zero code needed.
Custom Metrics
You can also track your own business metrics:
module.exports = {
name: "order",
async started() {
// Register a custom counter metric
this.broker.metrics.register({
type: "counter",
name: "order.created.total",
labelNames: ["status"],
description: "Total orders created"
});
// Register a custom gauge metric
this.broker.metrics.register({
type: "gauge",
name: "order.revenue.total",
description: "Total revenue from orders"
});
},
actions: {
create: {
async handler(ctx) {
const order = await this.adapter.insert(ctx.params);
// Increment your custom counter
this.broker.metrics.increment("order.created.total", {
status: "confirmed"
});
// Update your custom gauge
this.broker.metrics.increment(
"order.revenue.total",
null,
order.totalPrice
);
return order;
}
}
}
};
Now your Prometheus dashboard shows business metrics alongside system metrics. You can see total orders created and total revenue in real time.
Pillar 3: Tracing
This is the most powerful observability tool for microservices. Tracing shows you the complete journey of a single request as it travels through multiple services.
Without tracing, when a request is slow or fails, you know something went wrong but not where. With tracing you can see:
- request started at API Gateway at 10:00:00.000
- API Gateway called order.create at 10:00:00.005 — took 250ms
- order.create called user.get at 10:00:00.010 — took 50ms
- order.create called product.get at 10:00:00.060 — took 30ms
- order.create called product.reduceStock at 10:00:00.090 — took 80ms
- order.create completed at 10:00:00.255
- API Gateway responded at 10:00:00.260
You can see exactly where time was spent. If product.get took 5 seconds suddenly, you know immediately where to look.
Enabling Tracing in moleculer.config.js
module.exports = {
tracing: {
enabled: true,
exporter: [
// Console exporter — prints trace spans to terminal
// Good for development
{
type: "Console",
options: {
// Only log spans that take more than 5ms
// Reduces noise from fast operations
logger: null,
colors: true,
width: 100,
gaugeWidth: 40
}
},
// Jaeger exporter — sends traces to Jaeger UI
// Best tool for visualizing traces in development
{
type: "Jaeger",
options: {
// Jaeger collector endpoint
endpoint: null,
host: "localhost",
port: 6832,
// Send all spans (1.0 = 100%, 0.1 = 10%)
sampler: {
type: "Const",
options: { decision: 1 }
}
}
}
]
}
};
Setting Up Jaeger Locally
Jaeger is the most popular distributed tracing tool. Run it with Docker (we cover Docker fully in Post 14, but use this command now if you have Docker):
docker run -d --name jaeger \
-p 6831:6831/udp \
-p 16686:16686 \
jaegertracing/all-in-one:latest
Then open http://localhost:16686 in your browser. This is the Jaeger UI where you can visualize traces.
If you do not have Docker yet, use the Console exporter for now and come back to Jaeger in Post 14.
Console Tracing Output
With the Console exporter enabled, when you make a request you will see output like this in your terminal:
=== REQUEST TRACE ===
api.rest ████████████████████████ 255ms
order.create ██████████████████ 245ms
user.get ████ 50ms
product.get ███ 30ms
product.reduceStock ██████ 80ms
This visual representation shows you the full call chain and how long each step took.
Adding Custom Trace Spans
When you have a complex operation inside a single action, you can break it into named spans to see exactly where time is spent:
module.exports = {
name: "order",
actions: {
create: {
async handler(ctx) {
// Start a custom span for the validation step
const validationSpan = this.broker.tracer.startSpan(
"Validate order data",
{ parentSpan: ctx.span }
);
// Do validation work
await this.validateOrderData(ctx.params);
// End the validation span
validationSpan.finish();
// Start a span for the database insert
const dbSpan = this.broker.tracer.startSpan(
"Save order to database",
{ parentSpan: ctx.span }
);
const order = await this.adapter.insert(ctx.params);
dbSpan.finish();
return order;
}
}
}
};
Now in Jaeger you will see the order.create span broken into sub-spans showing exactly how long validation took versus database insertion.
Adding Tags to Spans
Tags let you attach metadata to a span so you can filter and search traces:
actions: {
create: {
async handler(ctx) {
// Add tags to the current span
ctx.span.setTag("userId", ctx.meta.user.id);
ctx.span.setTag("productId", ctx.params.productId);
ctx.span.setTag("quantity", ctx.params.quantity);
const order = await this.adapter.insert(ctx.params);
ctx.span.setTag("orderId", order._id.toString());
return order;
}
}
}
In Jaeger you can search for traces by tag. Find all orders for a specific user, or all orders for a specific product, by searching the tag values.
Complete Observability Configuration
Here is a complete moleculer.config.js with all three pillars enabled for production:
"use strict";
require("dotenv").config();
module.exports = {
namespace: "ecommerce",
nodeID: null,
// Logging
logger: [
{
type: "Console",
options: {
formatter: "full",
colors: true,
moduleColors: true,
autoPadding: true
}
},
{
type: "File",
options: {
filename: "logs/moleculer-{date}.log",
formatter: "json"
}
}
],
logLevel: {
"*": "warn",
"BROKER": "info",
"REGISTRY": "info"
},
// Metrics
metrics: {
enabled: true,
reporter: [
{
type: "Prometheus",
options: {
port: 3030,
path: "/metrics",
defaultLabels: (registry) => ({
namespace: registry.broker.namespace,
nodeID: registry.broker.nodeID
})
}
}
]
},
// Tracing
tracing: {
enabled: true,
exporter: [
{
type: "Console",
options: {
colors: true,
width: 100,
gaugeWidth: 40
}
},
{
type: "Jaeger",
options: {
host: process.env.JAEGER_HOST || "localhost",
port: 6832,
sampler: {
type: "Const",
options: { decision: 1 }
}
}
}
]
},
// Fault tolerance
requestTimeout: 10 * 1000,
retryPolicy: {
enabled: true,
retries: 3,
delay: 100,
maxDelay: 2000,
factor: 2,
check: err => err && !!err.retryable
},
circuitBreaker: {
enabled: true,
threshold: 0.5,
minRequestCount: 20,
windowTime: 60,
halfOpenTime: 10 * 1000,
check: err => err && err.code >= 500
},
bulkhead: {
enabled: true,
concurrency: 10,
maxQueueSize: 100
},
// Caching
cacher: {
type: "Memory",
options: {
ttl: 30
}
},
transporter: null
};
What to Do When Something Goes Wrong in Production
Here is a practical debugging workflow using all three pillars together:
Step 1: Check metrics first. Look at your Grafana dashboard. Which action has a spike in error rate or response time? Suppose you see order.create response time jumped from 50ms to 5000ms.
Step 2: Open Jaeger and filter traces for order.create in the last 30 minutes. Sort by duration. Open the slowest trace.
Step 3: The trace shows order.create called product.get and that took 4900ms. Everything else was normal.
Step 4: Check your logs filtered by the requestID from the slow trace. You see a MongoDB query timeout in the product service.
Step 5: Fix the MongoDB index on the product collection. Response time drops back to normal.
In five steps you went from knowing something is wrong to knowing exactly what and why. Without observability this could take hours.
Summary
- Observability has three pillars: Logging, Metrics, Tracing.
- Logging records what happened. Use structured JSON logging in production. Use appropriate log levels.
- Multiple loggers can run simultaneously — console for development, file for production.
- logLevel can be set per service for fine-grained control.
- Metrics track system performance numbers. Moleculer tracks request counts, response times, errors, and memory automatically.
- Prometheus reporter exposes metrics at an HTTP endpoint. Grafana reads Prometheus to create dashboards.
- Custom metrics let you track business numbers like total orders and total revenue.
- Tracing records the complete journey of each request through all services.
- Each hop in the call chain creates a span. Spans are organized into a trace tree.
- Jaeger is the best tool for visualizing traces locally.
- Use ctx.span.setTag() to attach searchable metadata to traces.
- The debugging workflow: metrics to find the problem, tracing to locate it, logging to understand it.
Up Next
Post 13 covers Docker and Docker Compose — packaging each service into a container and running the entire application with one command. This is the final step before production deployment. We will containerize all our services, add MongoDB and Redis containers, and wire everything together with a transporter.
Course Progress: 12 of 15 posts complete.