Improve batch worker error log serialization and test assertions#591
Improve batch worker error log serialization and test assertions#591
Conversation
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Run ID: 📒 Files selected for processing (7)
🚧 Files skipped from review as they are similar to previous changes (1)
WalkthroughAdds an ESLint Estimated code review effort🎯 3 (Moderate) | ⏱️ ~30 minutes 🚥 Pre-merge checks | ✅ 2 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (2 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 |
cmraible
force-pushed
the
improve-error-logging
branch
from
b906863 to
ceb2872
Compare
🤖 Velo CI Failure AnalysisClassification: 🟠 SOFT FAIL
|
cmraible
force-pushed
the
improve-error-logging
branch
from
ceb2872 to
52ca8c9
Compare
src/services/events/publisher.ts
Outdated
| const errorMessage = error instanceof Error ? error.message : String(error); | ||
| logger.error({ | ||
| event: 'EventPublishFailed', | ||
| error: errorMessage, | ||
| err: errorMessage, |
There was a problem hiding this comment.
we should log the whole error here, not just the error message.
| messageId: message.id, | ||
| messageData: this.getMessageData(message), | ||
| error | ||
| err: error |
There was a problem hiding this comment.
Let's rename error to err, so we can just pass it in the object as-is
cmraible
force-pushed
the
improve-error-logging
branch
from
52ca8c9 to
af99306
Compare
Pino only auto-serializes errors (message, stack) on the `err` key. Using `error` silently loses structured error data in production logs.
Rename `error` to `err` in all logger calls so Pino's error serializer properly extracts message and stack trace in structured logs.
cmraible
force-pushed
the
improve-error-logging
branch
from
af99306 to
185bbb5
Compare
🤖 Velo CI Failure AnalysisClassification: 🟠 SOFT FAIL
|
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 1
🧹 Nitpick comments (3)
test/unit/services/user-signature/UserSignatureService.test.ts (1)
296-313: Assert the serialized error log here.This still only checks the raw spy argument. Since the behavior change is Pino serializing
err, this test can pass even if the emitted log no longer contains the serializedmessage/stack. Consider switching this case tocreateInMemoryLogCapture()and asserting the parsed log entry instead, like the batch-worker tests.🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@test/unit/services/user-signature/UserSignatureService.test.ts` around lines 296 - 313, Replace the current spy-based assertion with an in-memory log capture so you can assert the serialized log payload: instead of spying on logger.error (loggerErrorSpy) set up createInMemoryLogCapture() before instantiating UserSignatureService(mockSaltStore), trigger the timeoutCallback from setTimeoutSpy as before, then parse the captured log entry and assert it contains event: 'SaltCleanupFailed' and that the serialized err includes error.message ('Cleanup failed') and err.stack; keep the mockRejectedValue on mockSaltStore.cleanup to simulate the error and still assert cleanupSpy was called..eslintrc.cjs (1)
7-13: Broaden this selector to catch logger patterns beyond theloggerbinding.This rule only enforces the
errconvention for calls likelogger.error({error: ...}). The codebase also usesrequest.log.error(),reply.log.error(), andfastify.log.*()witherrorfields that remain uncaught, leaving enforcement incomplete.Example unmatched patterns in codebase
request.log.error({event: ..., error: ...})in src/handlers/page-hit-handlers.ts (lines 14, 118)reply.log.error({event: ..., error: ...})in src/handlers/page-hit-handlers.ts (line 81)request.log.error({event: ..., error: ...})in src/plugins/hmac-validation.ts (line 68)request.log.warn({event: ..., error: ...})in src/plugins/hmac-validation.ts (line 36)🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In @.eslintrc.cjs around lines 7 - 13, Update the ESLint rule selector in .eslintrc.cjs so it matches any member call that logs errors (not only calls on an identifier named "logger"); replace the current selector with one that targets CallExpression nodes whose callee is a MemberExpression with property.name 'error' (and where the first argument is an ObjectExpression containing a Property with key.name 'error'), e.g. use a selector like "CallExpression[callee.type='MemberExpression'][callee.property.name='error'] > ObjectExpression > Property[key.name='error']" so patterns such as request.log.error(...), reply.log.error(...), fastify.log.error(...), etc. are caught.test/unit/services/batch-worker/batch-worker.test.ts (1)
72-75: Addawait drain()before clearing and reading the log capture to prevent race conditions.The test setup calls
getLogCapture().clear()inbeforeEach()without awaitingdrain(), and multiple test assertions callgetLogCapture().findByEvent()immediately after async operations without draining. Since Pino may queue writes internally before flushing to the stream, this creates a race condition where log entries can be missed or leak across tests. MakebeforeEach()async and addawait getLogCapture().drain()beforeclear(), and before eachfindByEvent()call in assertions that follow async operations.🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@test/unit/services/batch-worker/batch-worker.test.ts` around lines 72 - 75, Make the test setup await pending log writes to avoid races: change the beforeEach to be async and call await getLogCapture().drain() before getLogCapture().clear(); also, in tests that call getLogCapture().findByEvent() after async work, insert await getLogCapture().drain() immediately before each findByEvent() to ensure all Pino writes have flushed. Ensure you reference getLogCapture(), drain(), clear(), findByEvent(), and the beforeEach hook when applying the changes.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Inline comments:
In `@src/services/batch-worker/BatchWorker.ts`:
- Around line 185-190: The catch in flushBatch() logs this.batch metadata which
is cleared before the error; change the log to use the copied batch
(batchToFlush) instead of this.batch so batchSize and messageIds reflect the
items that failed to flush; update the logger.error call to use
batchToFlush.length and batchToFlush.map(item => item.message.id) (or a
similarly named local copy used in flushBatch()) and preserve the err field.
---
Nitpick comments:
In @.eslintrc.cjs:
- Around line 7-13: Update the ESLint rule selector in .eslintrc.cjs so it
matches any member call that logs errors (not only calls on an identifier named
"logger"); replace the current selector with one that targets CallExpression
nodes whose callee is a MemberExpression with property.name 'error' (and where
the first argument is an ObjectExpression containing a Property with key.name
'error'), e.g. use a selector like
"CallExpression[callee.type='MemberExpression'][callee.property.name='error'] >
ObjectExpression > Property[key.name='error']" so patterns such as
request.log.error(...), reply.log.error(...), fastify.log.error(...), etc. are
caught.
In `@test/unit/services/batch-worker/batch-worker.test.ts`:
- Around line 72-75: Make the test setup await pending log writes to avoid
races: change the beforeEach to be async and call await getLogCapture().drain()
before getLogCapture().clear(); also, in tests that call
getLogCapture().findByEvent() after async work, insert await
getLogCapture().drain() immediately before each findByEvent() to ensure all Pino
writes have flushed. Ensure you reference getLogCapture(), drain(), clear(),
findByEvent(), and the beforeEach hook when applying the changes.
In `@test/unit/services/user-signature/UserSignatureService.test.ts`:
- Around line 296-313: Replace the current spy-based assertion with an in-memory
log capture so you can assert the serialized log payload: instead of spying on
logger.error (loggerErrorSpy) set up createInMemoryLogCapture() before
instantiating UserSignatureService(mockSaltStore), trigger the timeoutCallback
from setTimeoutSpy as before, then parse the captured log entry and assert it
contains event: 'SaltCleanupFailed' and that the serialized err includes
error.message ('Cleanup failed') and err.stack; keep the mockRejectedValue on
mockSaltStore.cleanup to simulate the error and still assert cleanupSpy was
called.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: 1e57acb7-0be5-4398-9441-3ca5a456f9d3
📒 Files selected for processing (9)
.eslintrc.cjssrc/services/batch-worker/BatchWorker.tssrc/services/events/publisher.tssrc/services/salt-store/FileSaltStore.tssrc/services/salt-store/FirestoreSaltStore.tssrc/services/user-signature/UserSignatureService.tstest/unit/services/batch-worker/batch-worker.test.tstest/unit/services/user-signature/UserSignatureService.test.tstest/utils/log-capture.ts
Snapshot batch size and message IDs before calling flushBatch(), which clears this.batch before throwing. Previously the log would always show batchSize: 0 and messageIds: [].
Add second AST selector for CallExpression[callee.object.property.name='log']
to catch *.log.error({ error: ... }) patterns in addition to the existing
logger.error({ error: ... }) pattern.
Fix violations in page-hit-handlers, hmac-validation, and error-formatters.
Update corresponding test assertions.
2 participants
Summary
errfield so error message and stack are serialized in structured logstest/utils/log-capture.ts