fix: replace console.log with structured pino logger in API startup#214
fix: replace console.log with structured pino logger in API startup#214sputnik-mac wants to merge 1 commit intoalexanderwanyoike:devfrom
Conversation
📝 WalkthroughWalkthroughThe PR adds Changes
Estimated code review effort🎯 2 (Simple) | ⏱️ ~12 minutes Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment Tip You can disable the changed files summary in the walkthrough.Disable the |
There was a problem hiding this comment.
Actionable comments posted: 2
🧹 Nitpick comments (1)
api/src/main.ts (1)
4-8: Use env-driven log level for the bootstrap logger.Line 8 initializes Pino with defaults, so bootstrap logs ignore
LOG_LEVELcontrols used by the app logger. Consider wiring level from env for consistency.Proposed change
-const bootstrapLogger = pino({ name: "bootstrap" }); +const bootstrapLogger = pino({ + name: "bootstrap", + level: process.env.LOG_LEVEL || "info", +});🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@api/src/main.ts` around lines 4 - 8, The bootstrap logger is created without using the environment-controlled log level, so update the pino initialization in main.ts to read the LOG_LEVEL env var (e.g., process.env.LOG_LEVEL) and pass it as the level option when calling pino; modify the bootstrapLogger creation (the pino(...) call) to use that env value (with a sensible default like "info") so bootstrapLogger respects the same LOG_LEVEL as the rest of the app.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Inline comments:
In `@api/package.json`:
- Line 57: Change the conflicting dependency so pino-http's peer requirement is
satisfied: update the "pino" dependency in package.json from "^9.6.0" to
"^10.0.0" (or alternatively downgrade "pino-http" to a version compatible with
pino "^9.6.0"), then run yarn install in the api/ directory and commit the
resulting lockfile so CI's yarn install --frozen-lockfile will succeed; target
the "pino" and "pino-http" entries when making the change.
In `@api/src/main.ts`:
- Around line 44-45: Replace the immediate process.exit(1) call after
bootstrapLogger.error to allow pino to flush: set process.exitCode = 1 and
return from the bootstrap/startup flow instead of calling process.exit(1), so
leave the bootstrapLogger.error(...) call intact but replace the terminating
call (process.exit(1)) with assigning process.exitCode = 1 and returning from
the function that runs startup (where main/bootstrap logic executes) to let logs
be flushed.
---
Nitpick comments:
In `@api/src/main.ts`:
- Around line 4-8: The bootstrap logger is created without using the
environment-controlled log level, so update the pino initialization in main.ts
to read the LOG_LEVEL env var (e.g., process.env.LOG_LEVEL) and pass it as the
level option when calling pino; modify the bootstrapLogger creation (the
pino(...) call) to use that env value (with a sensible default like "info") so
bootstrapLogger respects the same LOG_LEVEL as the rest of the app.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Path: .coderabbit.yaml
Review profile: CHILL
Plan: Pro
Run ID: 551c1984-bb3f-4167-b5b0-4b03ea5e795c
📒 Files selected for processing (2)
api/package.jsonapi/src/main.ts
| "multer": "^2.0.1", | ||
| "nats": "^2.29.3", | ||
| "nestjs-pino": "^4.5.0", | ||
| "pino": "^9.6.0", |
There was a problem hiding this comment.
🧩 Analysis chain
🏁 Script executed:
# First, let's check if the api directory exists and see its structure
ls -la api/ 2>/dev/null | head -20Repository: alexanderwanyoike/the0
Length of output: 1017
🏁 Script executed:
# Check the current content of api/package.json around line 57
if [ -f "api/package.json" ]; then
echo "=== api/package.json (lines 50-65) ===" && sed -n '50,65p' api/package.json
else
echo "api/package.json not found"
fiRepository: alexanderwanyoike/the0
Length of output: 543
🏁 Script executed:
# Check what lockfiles exist in the api directory
ls -la api/package-lock.json api/yarn.lock 2>&1 | grep -v "cannot access"Repository: alexanderwanyoike/the0
Length of output: 130
🏁 Script executed:
# Search for CI configuration files and frozen-lockfile references
find . -maxdepth 2 -type f \( -name ".github" -o -name "*.yml" -o -name "*.yaml" \) 2>/dev/null | head -20Repository: alexanderwanyoike/the0
Length of output: 164
🏁 Script executed:
# Look for CI workflow files
find .github -type f -name "*.yml" -o -name "*.yaml" 2>/dev/nullRepository: alexanderwanyoike/the0
Length of output: 643
🏁 Script executed:
# Check the api.yml workflow file for frozen-lockfile instructions
cat -n .github/workflows/api.ymlRepository: alexanderwanyoike/the0
Length of output: 2694
🏁 Script executed:
# Also check what's actually in the api directory to understand the structure
ls -la api/Repository: alexanderwanyoike/the0
Length of output: 1017
🏁 Script executed:
# Check if pino is in the yarn.lock file
grep -n "pino" api/yarn.lock | head -20Repository: alexanderwanyoike/the0
Length of output: 1478
🏁 Script executed:
# Let's also check the full dependency section in package.json to understand the context
head -70 api/package.json | tail -25Repository: alexanderwanyoike/the0
Length of output: 740
🏁 Script executed:
# Check what version of pino-http requires and whether it conflicts with pino ^9.6.0
grep -A5 "pino-http@\^11.0.0:" api/yarn.lockRepository: alexanderwanyoike/the0
Length of output: 372
🏁 Script executed:
# Check if there are any other pino entries in the lockfile that could satisfy ^9.6.0
grep "^pino@" api/yarn.lockRepository: alexanderwanyoike/the0
Length of output: 79
🏁 Script executed:
# Let's get more context on the pino-http dependency and what it requires
grep -B2 -A10 "pino-http@\^11.0.0:" api/yarn.lockRepository: alexanderwanyoike/the0
Length of output: 497
🏁 Script executed:
# Check if pino-http requires pino ^10.0.0 specifically
grep -A20 "pino-http@\^11.0.0:" api/yarn.lock | grep -A5 "dependencies:"Repository: alexanderwanyoike/the0
Length of output: 336
🏁 Script executed:
# Let's see if pino ^9.6.0 exists in the lockfile at all
grep "^pino@\^9" api/yarn.lockRepository: alexanderwanyoike/the0
Length of output: 48
Update the pino version to satisfy existing dependency constraints.
Line 57 adds "pino": "^9.6.0", but pino-http@^11.0.0 (already in dependencies) requires pino@^10.0.0. This version conflict will cause yarn install --frozen-lockfile to fail in CI. Either update pino to ^10.0.0 or downgrade pino-http to a version compatible with pino ^9.6.0, then run yarn install in api/ and commit the updated lockfile.
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.
In `@api/package.json` at line 57, Change the conflicting dependency so
pino-http's peer requirement is satisfied: update the "pino" dependency in
package.json from "^9.6.0" to "^10.0.0" (or alternatively downgrade "pino-http"
to a version compatible with pino "^9.6.0"), then run yarn install in the api/
directory and commit the resulting lockfile so CI's yarn install
--frozen-lockfile will succeed; target the "pino" and "pino-http" entries when
making the change.
| bootstrapLogger.error({ err: error }, "Failed to start the0 API"); | ||
| process.exit(1); |
There was a problem hiding this comment.
🧩 Analysis chain
🏁 Script executed:
# First, check if the file exists and examine lines around 44-45
if [ -f "api/src/main.ts" ]; then
echo "=== File: api/src/main.ts ==="
wc -l api/src/main.ts
echo "=== Lines 40-50 context ==="
sed -n '40,50p' api/src/main.ts | cat -n
else
echo "File api/src/main.ts not found"
git ls-files | grep "main.ts"
fiRepository: alexanderwanyoike/the0
Length of output: 367
🏁 Script executed:
# Search for bootstrap function and error handling patterns
rg "bootstrap.*catch|process\.exit" api/src/ -A 3 -B 3Repository: alexanderwanyoike/the0
Length of output: 2067
🏁 Script executed:
# Check how the logger is initialized to understand pino setup
rg "bootstrapLogger|pino|winston" api/src/main.ts -B 2 -A 2Repository: alexanderwanyoike/the0
Length of output: 801
🏁 Script executed:
# Check pino configuration and understand default behavior
rg "pino|transport|stream" api/src/main.ts api/src/app.module.ts -B 2 -A 2Repository: alexanderwanyoike/the0
Length of output: 559
🏁 Script executed:
# Check if there are any pino transport configurations or logging setup
fd -e ts -e js api/src | xargs grep -l "pino\|Logger" | head -10Repository: alexanderwanyoike/the0
Length of output: 399
🌐 Web query:
pino logger process.exit synchronous stdout flushing Node.js best practices
💡 Result:
In Node.js, when using Pino logger and calling process.exit, logs may not flush to stdout synchronously by default, potentially losing recent entries due to buffering in sonic-boom (Pino's underlying writer). This is a known issue discussed extensively in Pino GitHub issues since v5+. Best practices for synchronous stdout flushing before process.exit: 1. Use pino.destination explicitly (sonic-boom defaults to sync: true for stdout/files): import pino from 'pino'; const dest = pino.destination; // or pino.destination(1) for explicit stdout fd const logger = pino(dest); logger.info('Will flush'); process.exit(1); // Logs guaranteed due to synchronous writes This ensures writes are synchronous (fs.writeSync), preventing loss on abrupt exit. Performance trade-off: slower than async but safe for exit scenarios. 2. For async destinations (sync: false), call logger.flushSync or dest.flushSync before exit: const dest = pino.destination({ sync: false }); const logger = pino(dest); logger.info('Flush me'); dest.flushSync; // Synchronous buffer flush process.exit(1); Note: logger.flush is async (fire-and-forget); use flushSync for blocking guarantee before exit. 3. Use logger.fatal: Automatically sync-flushes as it's designed for pre-exit logging. logger.fatal('Exiting with error'); process.exit(1); // Flushed automatically 4. Avoid transports like pino-pretty in production/exit-critical paths: They run in worker threads, causing flush races (Issue #1705). Use { sync: true } if needed, but prefer raw JSON for stdout. const stream = pino.transport({ target: 'pino-pretty', options: { sync: true } }); const logger = pino(stream); // Still risky on exit; test thoroughly 5. Graceful shutdown handlers (preferred for signals, not direct process.exit): import onExit from 'on-exit-leak-free'; // Used internally by Pino onExit( => { logger.flushSync; process.exit(0); }); Pino registers these automatically in modern Node (v14+), but direct process.exit bypasses 'beforeExit'. Direct process.exit terminates immediately after synchronous code, so synchronous writes/flushes are essential. For high-perf async logging, periodic logger.flush (e.g., every 10s) reduces risk, but sync destination is simplest for exit safety. Test: Modern Pino (v8+) with pino.destination reliably flushes on process.exit(1).
Citations:
- 1: Pino 5.8.1 fails to flush log on process exit pinojs/pino#542
- 2: Logs are not flushed, missing log entries after process.exit() pinojs/pino#1705
- 3: https://stackoverflow.com/questions/61347742/pino-loses-log-entries-on-process-exit
- 4: https://github.com/pinojs/pino/blob/main/docs/api.md
- 5: https://github.com/pinojs/pino/blob/HEAD/docs/asynchronous.md
- 6: Make pino.destination sync pinojs/pino#566
- 7: https://stackoverflow.com/questions/70265186/using-pino-multistream-with-synchronous-logging
- 8: https://github.com/pinojs/sonic-boom
Ensure error logs flush before exiting during bootstrap failures.
Line 46 calls process.exit(1) immediately after logging; this can truncate the fatal error log because process.exit() bypasses Node's graceful shutdown and stream flushing. Use process.exitCode = 1 with return to allow pino to flush logs to stdout before termination.
Proposed change
bootstrap().catch((error) => {
bootstrapLogger.error({ err: error }, "Failed to start the0 API");
- process.exit(1);
+ process.exitCode = 1;
+ return;
});📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| bootstrapLogger.error({ err: error }, "Failed to start the0 API"); | |
| process.exit(1); | |
| bootstrap().catch((error) => { | |
| bootstrapLogger.error({ err: error }, "Failed to start the0 API"); | |
| process.exitCode = 1; | |
| return; | |
| }); |
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.
In `@api/src/main.ts` around lines 44 - 45, Replace the immediate process.exit(1)
call after bootstrapLogger.error to allow pino to flush: set process.exitCode =
1 and return from the bootstrap/startup flow instead of calling process.exit(1),
so leave the bootstrapLogger.error(...) call intact but replace the terminating
call (process.exit(1)) with assigning process.exitCode = 1 and returning from
the function that runs startup (where main/bootstrap logic executes) to let logs
be flushed.
|
Hey @sputnik-mac, CI is failing because Also heads up, |
alexanderwanyoike
left a comment
There was a problem hiding this comment.
Have a look at the comment I mentioned above
What
Replaces
console.logandconsole.errorinapi/src/main.tswith a standalonepinologger instance for the bootstrap phase.Why
Startup messages (
Running database migrations...,Database migrations completed, and the fatal error handler) were usingconsole.log/console.error, producing unstructured plain text. The rest of the API emits structured JSON vianestjs-pino. This inconsistency breaks log aggregation in tools like Datadog, Loki, or CloudWatch.Changes
pinoas a direct dependency inapi/package.jsonbootstrapLoggerinstance with{ name: "bootstrap" }for pre-NestJS loggingconsole.log/console.errorcalls in bootstrap with structured equivalentsAll log output is now consistent structured JSON.
Closes #194
Summary by CodeRabbit
Release Notes