Skip to main content
observability Best practices for structured logging, correlation IDs, performance metrics, and debugging in Bun applications using @side-quest/core/logging and LogTape. Use when implementing logging, setting up observability, debugging production issues, tracking performance metrics, adding correlation IDs, configuring subsystem loggers, or working with JSONL log analysis. Covers plugin logger factory, hierarchical categories, log levels, metrics collection, and operational debugging workflows.
Zur Installation springen Skills Marktplatz Entdecken und erkunden Sie KI-Skills, die von der Community erstellt wurden.
Verwandte Berufe SOC
Basierend auf der SOC-Berufsklassifikation
Mit Codex oder Claude installieren Kopieren Sie diesen Prompt, fügen Sie ihn in Codex, Claude oder einen anderen Assistant ein und lassen Sie die Skill-Seite prüfen und installieren.
Prompt-Details anzeigen Ein direkter Befehl überspringt den Prüf-Prompt. Prüfen Sie die Quelle, bevor Sie ihn ausführen.
npx skills add https://github.com/nathanvale/side-quest-marketplace-old --skill observabilityDer Befehl bleibt in einer Zeile. Scrollen Sie horizontal, um ihn vor dem Kopieren vollständig zu prüfen.
Sie bevorzugen eine lokale Kopie? Laden Sie die Dateien herunter, die SkillsMP derzeit vorliegen.
ZIP herunterladen Herunterladen... Mehr aus diesem Repository Web scraping, site crawling, search, structured data extraction, and AI-powered research with Firecrawl CLI. Use when you need full page content as markdown, JS-rendered pages, anti-bot bypass, crawling entire documentation sites, extracting structured data with schemas, or deep web research. Prefer WebFetch for quick questions about a known URL. Prefer WebSearch for finding links without full content.
Build production-grade MCP (Model Context Protocol) servers with observability, correlation ID tracing, and dual logging. Use when creating new MCP servers, adding tools to existing servers, implementing file logging, debugging MCP issues, wrapping CLI tools with spawnSyncCollect, or following Side Quest marketplace patterns. Covers @side-quest/core/mcp declarative API, @side-quest/core/spawn CLI wrapper patterns, Zod schemas, Bun runtime, and 9 gold standard patterns validated across Kit plugin (18 tools). Includes error handling, response format switching, MCP annotations, and graceful degradation.
Unified inbox processor - handles ALL content types (clippings, transcriptions, VTT files, attachments) with parallel subagents and single-table review. Routes to appropriate creator based on proposed_template.
name observability description Best practices for structured logging, correlation IDs, performance metrics, and debugging in Bun applications using @side-quest/core/logging and LogTape. Use when implementing logging, setting up observability, debugging production issues, tracking performance metrics, adding correlation IDs, configuring subsystem loggers, or working with JSONL log analysis. Covers plugin logger factory, hierarchical categories, log levels, metrics collection, and operational debugging workflows. allowed-tools Read, Grep, Glob
Observability
Production-grade logging, metrics, and debugging patterns using @side-quest/core/logging (LogTape + JSONL).
Quick Navigation
Core Concepts
Structured Logging with LogTape Why LogTape: JSONL format enables programmatic analysis, grep filtering, and long-term storage.
Log Location: ~/.claude/logs/<plugin-name>.jsonl
JSONL (newline-delimited JSON) for machine parsing
File rotation (1 MiB default, keeps 5 files)
Hierarchical categories (plugin → subsystem)
Tagged template literals for clean syntax
Automatic timestamp, level, logger metadata
Hierarchical Categories
["para-obsidian" ]
["para-obsidian" , "inbox" ]
["para-obsidian" , "inbox" , "pdf" ]
Filter logs by subsystem
Different log levels per category
Trace operations across subsystems
Correlation IDs Purpose: Link related log entries across subsystems for request tracing.
import { createCorrelationId } from "@side-quest/core/logging" ;
const cid = createCorrelationId ();
inboxLogger.info `Scan started cid=${cid} ` ;
pdfLogger.debug `Extracting file cid=${cid} ` ;
llmLogger.info `Detection complete cid=${cid} ` ;
executeLogger.info `Note created cid=${cid} ` ;
Plugin Logger Setup
Factory Pattern ALWAYS use createPluginLogger() from @side-quest/core/logging:
import {
createCorrelationId,
createPluginLogger,
} from "@side-quest/core/logging" ;
const {
initLogger,
rootLogger,
getSubsystemLogger,
subsystemLoggers,
logFile,
} = createPluginLogger ({
name : "my-plugin" ,
subsystems : ["scraper" , "auth" , "api" ],
});
export { createCorrelationId, initLogger, logFile, rootLogger };
export const scraperLogger = subsystemLoggers.scraper ;
export const authLogger = subsystemLoggers.auth ;
export const apiLogger = subsystemLoggers.api ;
Option Required Default Description name✅ — Plugin name (kebab-case), used for log file subsystems❌ []Subsystem names for hierarchical logging logDir❌ ~/.claude/logsLog directory path logFileName❌ nameLog file name (without extension) maxSize❌ 1 MiB Max file size before rotation maxFiles❌ 5 Number of rotated files to keep lowestLevel❌ "debug"Minimum log level
Initialization ALWAYS call initLogger() before logging:
import { initLogger, scraperLogger } from "./logger" ;
async function main (await initLogger ();
scraperLogger.info `Application started` ;
}
main ();
Creates log directory if missing
Configures LogTape sinks and formatters
Logs initialization event (plugin, logDir, maxSize)
Safe to call multiple times (only initializes once)
Recommended: Emit a one-time “logger initialized” INFO with logFile, logDir, and lowestLevel so users can confirm where JSONL is written (especially when overriding to a vault-synced path).
Subsystem Logger Naming Convention: Match subsystem name to functional area:
Plugin Subsystems Use Cases cinema-bandit scraper, pricing, auth, gmailFunctional modules kit ast, semantic, gitTool categories
Anti-pattern: Don't use generic names like "utils", "helpers", "common"
Log Levels & Best Practices
Level Guidelines
pdfLogger.debug `Trying selector attempt=${attempt} selector="${sel} "` ;
pdfLogger.debug `Hash calculated file=${filename} hash=${hash} duration=${ms} ms` ;
inboxLogger.info `Scan started vault=${vaultPath} cid=${cid} ` ;
scraperLogger.info `Scrape complete movies=${count} duration=${ms} ms` ;
inboxLogger.warn `Skipping already processed: ${filename} ` ;
llmLogger.warn `LLM detection failed, using fallback confidence` ;
executeLogger.error `Failed to create note: ${error.message} cid=${cid} ` ;
authLogger.error `OAuth token refresh failed: ${error} ` ;
Logging Patterns
Pattern 1: Operation Tracing (Start → Complete) const cid = createCorrelationId ();
const startTime = Date .now ();
scraperLogger.info `Scrape started url=${url} cid=${cid} ` ;
try {
const result = await scrape (url);
const duration = Date .now () - startTime;
scraperLogger.info `Scrape complete movies=${result.length} duration=${duration} ms cid=${cid} ` ;
return result;
} catch (error) {
const duration = Date .now () - startTime;
scraperLogger.error `Scrape failed error=${error.message} duration=${duration} ms cid=${cid} ` ;
throw error;
}
Trace operation lifecycle
Measure performance (duration)
Link failure to operation start (cid)
Pattern 2: Conditional Debug Logging
for (const selector of selectors) {
pdfLogger.debug `Trying selector="${selector} "` ;
const element = await page.locator (selector).first ();
if (await element.isVisible ()) {
pdfLogger.debug `Selector matched="${selector} "` ;
return element;
}
}
pdfLogger.warn `No selectors matched - using fallback` ;
Why: DEBUG logs can be voluminous; use INFO for successes.
Pattern 3: Structured Logging (Recommended) Use structured logs with properties object instead of template literals:
inboxLogger.info ("Bookmark enrichment started" , {
event : "enrichment_started" ,
sessionCid,
cid,
parentCid,
file : file.filename ,
url,
timestamp : new Date ().toISOString (),
});
inboxLogger.info `Bookmark enrichment started file=${file.filename} url=${url} ` ;
Easier jq queries: jq 'select(.properties.event == "enrichment_started")'
Consistent field structure across logs
Type safety with TypeScript
Better for automated analysis
jq 'select(.properties.event == "enrichment_started")' ~/.claude/logs/para-obsidian.jsonl
jq 'select(.properties.template == "invoice")' ~/.claude/logs/para-obsidian.jsonl
jq 'select(.properties.durationMs > 1000)' ~/.claude/logs/para-obsidian.jsonl
"scan_started" , "scan_complete"
"file_processing_started"
"enrichment_started" , "enrichment_ended"
"pdf_extraction_complete"
PII safety: When logs sync to cloud storage, mask or omit sensitive extracted fields (names, amounts, IDs) before logging. Prefer short summaries or hashed values over raw content.
Log Level Convention Table Level Volume Use Case Example DEBUG High Detailed diagnostics, loops, retries Selector attempts, hash calculations INFO Medium Milestones, summaries, timing Scan started/complete, item counts WARN Low Degraded operation, edge cases Skipped files, fallback logic ERROR Very Low Operation failures, exceptions Create failed, validation error
Correlation ID Patterns
OpenTelemetry-Compatible Three-Tier Hierarchy Based on W3C Trace Context specification, used in production at para-obsidian:
acdfe223 (Session: para scan, 3.2s)
├─ e400fff2: inbox:scan (parent: acdfe223)
│ ├─ df2b9fd7: inbox:processPdf (parent: e400fff2, session: acdfe223)
│ ├─ eae519bd: enrich:bookmark (parent: e400fff2, session: acdfe223)
│ └─ 45c84df0: inbox:skipFastPath (parent: e400fff2, session: acdfe223)
Pattern 1: Session-Level Tracking (Recommended) Use when: You have a top-level operation (CLI command, MCP request) that spawns multiple sub-operations.
interface ProcessFileContext {
sessionCid : string ;
parentCid : string ;
file : InboxFile ;
}
async function scan (options ?: ScanOptions const sessionCid = createCorrelationId ();
const cid = createCorrelationId ();
inboxLogger.info ("Scan started" , {
event : "scan_started" ,
sessionCid,
cid,
vault : vaultPath,
timestamp : new Date ().toISOString (),
});
for (const file of files) {
await processSingleFile ({
sessionCid,
parentCid : cid,
file,
});
}
inboxLogger.info ("Scan complete" , {
event : "scan_complete" ,
sessionCid,
cid,
processed : files.length ,
durationMs : Date .now () - startTime,
timestamp : new Date ().toISOString (),
});
}
async function processSingleFile (ctx : ProcessFileContext const { sessionCid, parentCid, file } = ctx;
const cid = createCorrelationId ();
pdfLogger.info ("File processing started" , {
event : "file_processing_started" ,
sessionCid,
cid,
parentCid,
file : file.name ,
});
await enrichmentPipeline.processFile (file, {
sessionCid,
cid,
parentCid,
});
}
✅ End-to-end traceability across async operations
✅ Can trace all operations for a session: grep sessionCid=acdfe223
✅ Can see parent-child relationships: grep parentCid=e400fff2
✅ Compatible with OpenTelemetry for future integration
Pattern 2: Per-Item Tracking (Legacy, Not Recommended) Use when: Simple scripts without session concept.
for (const file of files) {
const itemCid = createCorrelationId ();
try {
pdfLogger.info `Processing file=${file} cid=${itemCid} ` ;
const text = await extractPdf (file, itemCid);
const type = await detectType (text, itemCid);
pdfLogger.info `Processed file=${file} type=${type } cid=${itemCid} ` ;
} catch (error) {
pdfLogger.error `Failed file=${file} error=${error.message} cid=${itemCid} ` ;
}
}
Limitation: Cannot trace operations back to originating session.
Grep Debugging Workflow (Three-Tier IDs)
grep 'sessionCid=acdfe223' ~/.claude/logs/para-obsidian.jsonl
grep 'parentCid=e400fff2' ~/.claude/logs/para-obsidian.jsonl
grep -E '(cid=e400fff2|parentCid=e400fff2)' ~/.claude/logs/para-obsidian.jsonl
grep 'sessionCid=acdfe223' ~/.claude/logs/para-obsidian.jsonl | \
jq -r '."@timestamp" + " | " + (.properties.cid // "N/A") + " | " + (.properties.parentCid // "N/A") + " | " + .message'
grep 'sessionCid=acdfe223' ~/.claude/logs/para-obsidian.jsonl | \
jq -s 'group_by(.properties.parentCid) |
map({parent: .[0].properties.parentCid, children: map(.properties.cid)})'
Legacy single-CID workflow:
grep 'cid=a1b2c3d4' ~/.claude/logs/my-plugin.jsonl
grep 'cid=a1b2c3d4' ~/.claude/logs/my-plugin.jsonl | jq .
grep 'cid=a1b2c3d4' ~/.claude/logs/my-plugin.jsonl | jq -r '.message'
grep 'cid=a1b2c3d4' ~/.claude/logs/my-plugin.jsonl | \
jq -r '."@timestamp" + " | " + .level + " | " + .message'
Performance Metrics
Automatic Metrics Collection MetricsCollector
import { MetricsCollector } from "@side-quest/core/logging" ;
const collector = new MetricsCollector ();
await collector.collect ();
const summary = collector.getSummary ();
console .log (summary.toMarkdown ());
Include summaries in CLI/JSON output: After a run, return or print { metrics: summary, logFile } so users and automation can locate performance data and the corresponding JSONL file.
═══════════════════════════════════════════════════════════════
📊 MCP Performance Metrics - Session Summary
═══════════════════════════════════════════════════════════════
Total Operations: 150
Successful: 145 (96.7%)
Failed: 5 (3.3%)
Total Duration: 45.2s
───────────────────────────────────────────────────────────────
Tool Name Calls Avg Time Min Max Errors
───────────────────────────────────────────────────────────────
kit_index_find 25 12ms 8ms 45ms 0
bun_runTests 10 1250ms 980ms 1.5s 2
biome_lintCheck 8 180ms 120ms 250ms 0
───────────────────────────────────────────────────────────────
Slowest Operations:
1. bun_runTests (1.5s)
2. semantic_search (980ms)
...
Manual Metrics Logging For custom metrics, log durationMs property:
const startTime = Date .now ();
try {
const result = await operation ();
const durationMs = Date .now () - startTime;
scraperLogger.info `Operation complete` , {
tool : "scraper_fetch" ,
durationMs,
success : true ,
cid,
};
return result;
} catch (error) {
const durationMs = Date .now () - startTime;
scraperLogger.error `Operation failed` , {
tool : "scraper_fetch" ,
durationMs,
success : false ,
cid,
};
throw error;
}
MetricsCollector automatically aggregates:
Call counts
Min/max/avg latency
Error rates
Success rates
Querying Metrics Manually
jq 'select(.properties.tool == "kit_index_find") | .properties.durationMs' \
~/.claude/logs/kit.jsonl | \
awk '{sum+=$1; count++} END {print sum/count " ms"}'
jq 'select(.properties.tool == "bun_runTests") | .properties.success' \
~/.claude/logs/bun-runner.jsonl | \
sort | uniq -c
jq 'select(.properties.durationMs > 1000)' ~/.claude/logs/*.jsonl
Debugging Workflows
Common Grep Patterns
grep '"level":"error"' ~/.claude/logs/my-plugin.jsonl | tail -20
grep 'file=invoice-123.pdf' ~/.claude/logs/para-obsidian.jsonl
grep -E '"level":"(warn|error)"' ~/.claude/logs/my-plugin.jsonl
jq 'select(.properties.durationMs > 1000)' ~/.claude/logs/*.jsonl
JQ Analysis Patterns
jq -s 'group_by(.properties.error) |
map({error: .[0].properties.error, count: length})' \
~/.claude/logs/my-plugin.jsonl
jq -s 'group_by(.level) |
map({level: .[0].level, count: length})' \
~/.claude/logs/my-plugin.jsonl
jq -r '."@timestamp" + " | " + .properties.cid + " | " + .message' \
~/.claude/logs/my-plugin.jsonl
Discipline: Ensure every log in the flow carries cid (including skips, hash failures, LLM errors, and execute failures) so traces stay contiguous.
Production Debugging Checklist When debugging production issues:
Testing
Log Assertions in Tests import { describe, expect, test, beforeEach, afterEach } from "bun:test" ;
import { initLogger, scraperLogger } from "./logger" ;
describe ("Scraper" , () => {
beforeEach (async () => {
await initLogger ();
});
test ("logs scrape started" , async () => {
const result = await scrape (url);
expect (result).toBeDefined ();
expect (result.length ).toBeGreaterThan (0 );
});
});
Recommendation: Test functional behavior, not log output. Logs are for observability, not assertions.
Metrics Validation test ("MetricsCollector aggregates correctly" , () => {
const collector = new MetricsCollector ();
collector.recordOperation ("tool_a" , 100 , true );
collector.recordOperation ("tool_a" , 200 , true );
collector.recordOperation ("tool_b" , 50 , false );
const summary = collector.getSummary ();
expect (summary.totalOperations ).toBe (3 );
expect (summary.successfulOperations ).toBe (2 );
expect (summary.failedOperations ).toBe (1 );
const toolA = summary.toolMetrics .find (m =>tool === "tool_a" );
expect (toolA?.avgDurationMs ).toBe (150 );
expect (toolA?.successRate ).toBe (100 );
});
Common Patterns
Pattern 1: Subsystem Logger Per Module
import { scraperLogger, createCorrelationId } from "./logger" ;
export async function scrapeMovies (url : string const cid = createCorrelationId ();
scraperLogger.info `Scrape started url=${url} cid=${cid} ` ;
scraperLogger.info `Scrape complete count=${movies.length} cid=${cid} ` ;
return movies;
}
Pattern 2: Fallback Chains with Logging async function trySelectors (page, selectors ) {
for (const selector of selectors) {
pdfLogger.debug `Trying selector="${selector} "` ;
const element = await page.locator (selector).first ();
if (await element.isVisible ()) {
pdfLogger.debug `Selector matched="${selector} "` ;
return element;
}
}
pdfLogger.warn `All selectors failed - using default` ;
return defaultElement;
}
Pattern 3: Registry Updates with Logging async function updateRegistry (hash : string , notePath : string , cid : string debug `Updating registry hash=${hash} cid=${cid} ` ;
try {
await registry.markProcessed ({
sourceHash : hash,
processedAt : new Date ().toISOString (),
createdNote : notePath,
});
await registry.save ();
executeLogger.debug `Registry saved hash=${hash} cid=${cid} ` ;
} catch (error) {
executeLogger.error `Registry update failed hash=${hash} error=${error.message} cid=${cid} ` ;
throw error;
}
}
Pattern 4: Performance Tracking async function processItems (items : Item [], cid : string const overallStart = Date .now ();
let successCount = 0 ;
let failureCount = 0 ;
for (const item of items) {
const itemStart = Date .now ();
try {
await processItem (item, cid);
successCount++;
const duration = Date .now () - itemStart;
executeLogger.debug `Item processed file=${item.name} duration=${duration} ms cid=${cid} ` ;
} catch (error) {
failureCount++;
const duration = Date .now () - itemStart;
executeLogger.error `Item failed file=${item.name} duration=${duration} ms cid=${cid} ` ;
}
}
const totalDuration = Date .now () - overallStart;
executeLogger.info `Batch complete success=${successCount} failed=${failureCount} duration=${totalDuration} ms cid=${cid} ` ;
}
Quick Reference
File Structure plugins/my-plugin/
├── src/
│ ├── logger.ts # createPluginLogger setup + exports
│ ├── scraper.ts # Uses scraperLogger
│ ├── auth.ts # Uses authLogger
│ └── cli.ts # Calls initLogger()
└── mcp/
└── index.ts # Calls initLogger() in startup
Key Imports
import {
createCorrelationId,
createPluginLogger,
MetricsCollector ,
} from "@side-quest/core/logging" ;
Checklist: Adding Logging to a Plugin
Related Skills
Bun CLI Development
CLI entry point patterns (where to call initLogger())
Error handling with exit codes
Output formatting (markdown + JSON)
import { initLogger, scraperLogger } from "./logger" ;
async function main (await initLogger ();
const { command, flags } = parseArgs (process.argv .slice (2 ));
scraperLogger.info `CLI started command=${command} ` ;
}
main ();
Bun Runtime Workflows
Testing patterns (beforeEach/afterEach for initLogger)
Async/await best practices (initLogger is async)
Performance optimization (log levels impact throughput)
FAQ
When should I create a new subsystem logger? Create a new subsystem when:
Functional area is distinct (scraping, auth, storage)
You want independent log filtering (grep '"logger":"my-plugin.scraper"')
Module has significant enough volume to justify separation
Don't create subsystems for:
Utils/helpers (use root logger)
One-off operations (use root logger)
Overly granular divisions (too many subsystems = hard to filter)
Should I log in tests? Generally no. Tests should assert functional behavior, not log output.
Exception: When testing logging infrastructure itself (logger.ts, metrics.ts).
How do I rotate logs manually? Logs auto-rotate at 1 MiB (default). To force rotation:
mv ~/.claude/logs/my-plugin.jsonl ~/.claude/logs/my-plugin.jsonl.1
What's the difference between correlation ID and request ID? Correlation ID: 8-character UUID for tracing a single operation across subsystems.
Request ID: Typically longer, used for distributed tracing across services.
For local plugins, correlation IDs are sufficient.
How do I debug "no logs appearing"?
Verify initLogger() called: Logs won't appear until initializationCheck log level: DEBUG logs hidden if lowestLevel > "debug"Inspect log file directly: tail -f ~/.claude/logs/my-plugin.jsonlCheck LogTape errors: Look for "logtape.meta" ERROR logsVerify file permissions: Log directory must be writable
Production Reference Implementation
para-obsidian Plugin Location: plugins/para-obsidian/
Observability Maturity: 4/5 (Adaptive)
✅ OpenTelemetry-compatible three-tier CID hierarchy (sessionCid, cid, parentCid)
✅ Structured logging with properties objects across all subsystems
✅ End-to-end traceability across async operations (scan → classify → enrich → execute)
✅ Full trace correlation with parent-child relationships
✅ Subsystem loggers: inbox, pdf, llm, execute, git, enrich, search, templates, frontmatter, fs, lock, tx, cli, classify
src/shared/logger.ts - Plugin logger setup with 14 subsystemssrc/inbox/core/engine.ts - Session-level CID threading through file processingsrc/inbox/enrich/strategies/bookmark-strategy.ts - Structured logging in enrichmentOBSERVABILITY_IMPROVEMENTS.md - Complete implementation details and rationale {
"@timestamp" : "2025-12-20T21:37:26.567Z" ,
"level" : "info" ,
"logger" : "para-obsidian.enrich" ,
"message" : "Bookmark enrichment started" ,
"properties" : {
"event" : "enrichment_started" ,
"sessionCid" : "acdfe223" ,
"cid" : "eae519bd" ,
"parentCid" : "e400fff2" ,
"file" : "bookmark-example.md" ,
"url" : "https://example.com"
}
}
grep 'sessionCid=acdfe223' ~/.claude/logs/para-obsidian.jsonl
grep 'sessionCid=acdfe223' ~/.claude/logs/para-obsidian.jsonl | \
jq -r '."@timestamp" + " | " + .properties.cid + " | " + .message'
