Logging¶
RockLake uses structured logging via Rust's tracing crate, providing configurable verbosity levels, JSON output for machine parsing, contextual spans for correlating related log entries, and per-crate granularity for targeted debugging. Logs are your primary diagnostic tool when something goes wrong — they tell you what the system was doing, what it encountered, and how it responded.
This page covers log level configuration, structured JSON output, per-module filtering, common diagnostic scenarios, log aggregation integration, and best practices for production logging.
Log Output Destination¶
RockLake writes all log output to stderr by default. It does not write to files, rotate logs, or manage log lifecycle. This is intentional — your deployment platform (Docker, systemd, Kubernetes) handles log collection and rotation. RockLake's responsibility is producing useful log entries; your platform's responsibility is storing and managing them.
Log Levels¶
RockLake uses five standard log levels, each with a clear contract about what it captures:
| Level | Purpose | Volume | Production Use |
|---|---|---|---|
error | Unrecoverable failures requiring operator attention | Very low (0-1/hour normally) | Always on |
warn | Recoverable issues that may indicate problems | Low (< 10/hour normally) | Always on |
info | Operational milestones and state transitions | Medium (1-5/minute) | Default production level |
debug | Per-operation details for troubleshooting | High (100+/minute) | Temporary, during investigation |
trace | Wire-level protocol details and byte-level state | Very high (1000+/minute) | Never in production |
What Each Level Captures¶
Error — situations where an operation cannot be completed:
ERROR rocklake_catalog: Writer fenced - another writer has a higher epoch (theirs: 42, ours: 41)
ERROR rocklake_pgwire: TLS handshake failed: certificate expired
ERROR rocklake_catalog: Object storage unreachable after 3 retries: connection refused
Warn — problems that were handled but indicate something is suboptimal:
WARN rocklake_catalog: Object storage throttled (429), retrying in 500ms (attempt 2/3)
WARN rocklake_pgwire: Client sent unsupported SSL version (TLS 1.0), rejecting
WARN rocklake_catalog: GC blocked by 3 pinned snapshots older than 90 days
Info — normal operational events that mark important state transitions:
INFO rocklake: RockLake v0.8.0 starting
INFO rocklake: Storage: s3://my-bucket/catalog/
INFO rocklake: Listening on 0.0.0.0:5432
INFO rocklake: Writer epoch acquired: 42
INFO rocklake_pgwire: Session connected: remote=10.0.1.5:52431 session_id=abc123
INFO rocklake_pgwire: Session disconnected: session_id=abc123 duration=45m
INFO rocklake_catalog: Snapshot committed: id=1502 keys_written=7 duration=12ms
INFO rocklake_catalog: GC completed: horizon advanced to snapshot 1400, 102 snapshots collected
Debug — detailed operation traces for investigating specific issues:
DEBUG rocklake_catalog: Prefix scan: prefix=t/1/c/ keys_found=12 cache_hits=10 storage_reads=2 duration=3ms
DEBUG rocklake_sql: Statement classified: type=SELECT table=analytics.events
DEBUG rocklake_catalog: Hot key cache miss: key="t/1/latest" fetching from storage
DEBUG rocklake_pgwire: Extended query: parse="SELECT 1" bind=[] describe=true execute=true
Trace — byte-level details (never for production):
TRACE rocklake_pgwire: Received bytes: [51 00 00 00 04] (Query message, 4 bytes)
TRACE rocklake_catalog: SlateDB get: key=[116 47 49 47 108 97 116 65 115 116] -> Some(152 bytes)
TRACE rocklake_pgwire: Sending: RowDescription [name="count", oid=20, typlen=8]
Configuration¶
Environment Variable (RUST_LOG)¶
The RUST_LOG environment variable controls logging with fine-grained, per-module filtering:
# Standard production
RUST_LOG=info rocklake serve --catalog s3://bucket/catalog/
# Debug catalog operations only
RUST_LOG=info,rocklake_catalog=debug rocklake serve --catalog s3://bucket/catalog/
# Debug PG wire protocol handling
RUST_LOG=info,rocklake_pgwire=debug rocklake serve --catalog s3://bucket/catalog/
# Debug everything (noisy, use briefly)
RUST_LOG=debug rocklake serve --catalog s3://bucket/catalog/
# Multiple specific targets
RUST_LOG=info,rocklake_catalog=debug,rocklake_sql=debug,rocklake_pgwire=trace rocklake ...
CLI Flag¶
The --log-level flag sets a global level. For per-module control, use RUST_LOG.
Module Names¶
RockLake's log targets correspond to its crate names:
| Target | Crate | What It Logs |
|---|---|---|
rocklake | Main binary | Startup, shutdown, top-level config |
rocklake_catalog | rocklake-catalog | Key-value operations, MVCC, GC, snapshots |
rocklake_pgwire | rocklake-pgwire | Session lifecycle, protocol messages, TLS |
rocklake_sql | rocklake-sql | SQL parsing, classification, dispatch |
rocklake_core | rocklake-core | Shared types, encoding, protobuf |
rocklake_datafusion | rocklake-datafusion | DataFusion integration |
Structured JSON Output¶
For log aggregation systems (Elasticsearch, Loki, CloudWatch Logs, Datadog, Splunk), enable JSON-formatted output:
Or with CLI:
JSON Format¶
Each log line is a single JSON object:
{
"timestamp": "2024-03-15T14:30:22.456Z",
"level": "INFO",
"target": "rocklake_pgwire",
"message": "Session connected",
"fields": {
"remote_addr": "10.0.1.5:52431",
"session_id": "abc123",
"tls": true
},
"span": {
"name": "session",
"session_id": "abc123"
}
}
Structured Fields¶
Key fields included automatically:
| Field | Description |
|---|---|
timestamp | ISO 8601 timestamp with millisecond precision |
level | Log level (ERROR, WARN, INFO, DEBUG, TRACE) |
target | Rust module path (crate/module) |
message | Human-readable message |
fields | Contextual key-value pairs specific to the event |
span | Active tracing span context (for request correlation) |
Filtering JSON Logs¶
# Find all errors in the last hour
cat /var/log/rocklake.json | jq 'select(.level == "ERROR")'
# Find all session events for a specific client
cat /var/log/rocklake.json | jq 'select(.fields.remote_addr == "10.0.1.5:52431")'
# Count operations by type
cat /var/log/rocklake.json | jq 'select(.target == "rocklake_sql") | .fields.statement_type' | sort | uniq -c
Request Correlation¶
RockLake uses tracing spans to correlate log entries belonging to the same operation:
{"timestamp":"...","level":"DEBUG","message":"Prefix scan started","span":{"session_id":"abc123","query_id":"q-789"}}
{"timestamp":"...","level":"DEBUG","message":"Cache miss, reading from storage","span":{"session_id":"abc123","query_id":"q-789"}}
{"timestamp":"...","level":"DEBUG","message":"Prefix scan completed","span":{"session_id":"abc123","query_id":"q-789"},"fields":{"keys_found":12,"duration_ms":8}}
The session_id and query_id span fields let you trace a single operation across all log entries it produced.
Common Diagnostic Scenarios¶
Debugging a Slow Operation¶
# Temporarily increase verbosity for catalog operations
RUST_LOG=info,rocklake_catalog=debug rocklake ...
Look for:
cache missentries (indicates cold cache, storage reads)keys_scannedcounts (high numbers indicate missing indexes or full scans)storage_request_durationfields (high values indicate storage latency)
Investigating Writer Fencing¶
Look for:
WARN rocklake_catalog: Epoch check failed: stored_epoch=43, our_epoch=42
ERROR rocklake_catalog: Writer fenced - shutting down
This means another instance has taken the writer role. Check for accidental duplicate deployments.
Troubleshooting Connection Failures¶
Look for:
TLS handshake failed— certificate issuesAuthentication failed— wrong passwordSession limit reached— max sessions exhaustedConnection reset by peer— client disconnected ungracefully
Diagnosing Object Storage Issues¶
Look for:
storage throttled (429)— rate limiting, back offstorage error: connection refused— endpoint unreachablestorage error: access denied— credential issuesretry attempt 2/3— transient failures being handled
Log Aggregation Integration¶
Docker (JSON File Driver)¶
services:
rocklake:
environment:
ROCKLAKE_LOG_FORMAT: json
logging:
driver: json-file
options:
max-size: "50m"
max-file: "5"
Kubernetes (stdout → cluster log collector)¶
Kubernetes captures stdout/stderr automatically. Use a DaemonSet log collector (Fluentd, Fluent Bit, Vector):
# Fluent Bit parser for RockLake JSON logs
[PARSER]
Name rocklake
Format json
Time_Key timestamp
Time_Format %Y-%m-%dT%H:%M:%S.%LZ
systemd Journal¶
When running under systemd, logs go to the journal automatically:
# View RockLake logs
journalctl -u rocklake -f
# Filter by level
journalctl -u rocklake -p err
# Export structured fields
journalctl -u rocklake -o json | jq '.MESSAGE | fromjson | select(.level == "ERROR")'
AWS CloudWatch Logs¶
{
"logs": {
"logs_collected": {
"files": {
"collect_list": [
{
"file_path": "/var/log/rocklake/*.json",
"log_group_name": "/rocklake/production",
"log_stream_name": "{instance_id}"
}
]
}
}
}
}
Performance Impact of Logging¶
Logging has measurable overhead. The impact by level:
| Level | Overhead | Notes |
|---|---|---|
error + warn + info | <1% | Negligible, always safe |
debug | 2–5% | Acceptable for short investigation |
trace | 10–30% | Significant, never in production |
The overhead comes from:
- String formatting (even if the message is not emitted — use
tracingmacros which avoid this) - I/O writes to stderr
- JSON serialization (slightly more than text format)
Best Practices¶
- Use
infolevel in production. It provides sufficient visibility without noise. - Use JSON format with log aggregation. Structured logs enable powerful filtering and alerting.
- Never use
tracein production. It produces gigabytes of output per hour. - Escalate temporarily for debugging. Change
RUST_LOGvia environment variable, investigate, then revert. - Monitor log volume. A sudden increase in log volume (especially errors/warnings) is itself a signal.
- Retain logs for at least 7 days. Allows post-incident investigation.
Common Log Patterns and What They Mean¶
Startup Sequence (Healthy)¶
A healthy startup produces exactly this sequence:
INFO rocklake: RockLake v0.8.0 starting
INFO rocklake: Storage: s3://my-bucket/catalog/
INFO rocklake_catalog: Opening SlateDB at s3://my-bucket/catalog/
INFO rocklake_catalog: Manifest loaded: format_version=1, latest_snapshot=1247
INFO rocklake_catalog: Writer epoch acquired: 42
INFO rocklake: Listening on 0.0.0.0:5432 (TLS enabled)
INFO rocklake: Metrics endpoint on 0.0.0.0:9090/metrics
INFO rocklake: Ready to accept connections
If any of these lines are missing, something interrupted startup.
Storage Throttling (Transient)¶
WARN rocklake_catalog: Storage throttled (HTTP 429), backing off 200ms
WARN rocklake_catalog: Storage throttled (HTTP 429), backing off 400ms
INFO rocklake_catalog: Storage request succeeded after 2 retries
This is normal under load. S3 throttles at the prefix level. If this occurs frequently, consider using S3 Express One Zone or spreading data across multiple prefixes.
Client Protocol Error (Non-Critical)¶
WARN rocklake_pgwire: Unrecognized SQL pattern from session abc123: "SHOW search_path"
WARN rocklake_pgwire: Responding with SQLSTATE 42601 (syntax error)
This means a client sent SQL that does not match any known DuckDB pattern. If the client is DuckDB and this happens, it may indicate a version incompatibility — check whether the DuckDB version is supported.
Memory Pressure (Investigate)¶
WARN rocklake: Memory usage approaching limit: 450MB / 512MB
WARN rocklake: Evicting block cache entries to free memory
This suggests the instance needs more memory or the max-sessions limit should be reduced.
Correlating Logs Across Components¶
In a production deployment with multiple components (DuckDB clients, RockLake server, object storage), correlating events across systems requires shared identifiers:
| Component | Correlation Key | Where to Find |
|---|---|---|
| DuckDB | Connection ID | Client-side connection string |
| RockLake | Session ID | Logged with every session event |
| Object Storage | Request ID | S3 response headers (x-amz-request-id) |
| Load Balancer | Trace ID | X-Request-ID header (if configured) |
When investigating a slow query reported by a DuckDB user: 1. Get the session ID from RockLake logs (correlate by timestamp and client IP) 2. Filter all logs for that session: session_id=abc123 3. Look for storage latency spikes in that session's operations 4. If storage was slow, use the S3 request ID from debug logs to check CloudTrail
Further Reading¶
- Monitoring — Metrics-based observability (complements logging)
- Troubleshooting — Using logs to diagnose specific problems
- Configuration — Log format and level settings