-
-
Notifications
You must be signed in to change notification settings - Fork 3k
perf: don't log settings.loadTest warning per-message (#7756)#7776
perf: don't log settings.loadTest warning per-message (#7756) #7776JohnMcLear wants to merge 2 commits into
Conversation
CPU profile of develop (and of the open #7775 branch) at the 100-400 author dive sweep attributed ~4% of total process CPU to log4js inside SecurityManager.checkAccess. Tracing the actual log call: line 79-80 emits `console.warn('bypassing socket.io authentication...')` on every checkAccess invocation when settings.loadTest is true — once per inbound message. With log4js's replaceConsole + cluster-mode dispatch enabled, that warning allocated, formatted, and dispatched a LogEvent through sendToListeners -> sendLogEventToAppender for every CLIENT_READY, COMMIT_CHANGESET, USERINFO_UPDATE, etc. settings.loadTest is a configuration choice, not a per-request condition. The warning belongs at startup. Move it to Settings.ts init alongside the other "you set X, beware" warnings, and drop the per-message branch (the loadTest short-circuit still applies). Test plan: - tests/backend/specs/api/sessionsAndGroups.ts: 32 passing - tests/backend/specs/socketio.ts: 39 passing (handleMessage paths) Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Qodo reviews are paused for this user.
Troubleshooting steps vary by plan Learn more →
On a Teams plan?
Reviews resume once this user has a paid seat and their Git account is linked in Qodo.
Link Git account →
Using GitHub Enterprise Server, GitLab Self-Managed, or Bitbucket Data Center?
These require an Enterprise plan - Contact us
Contact us →
Review Summary by Qodo
Move loadTest warning to startup, eliminate per-message logging overhead
✨ Enhancement
Walkthroughs
Description
• Move loadTest warning from per-message to startup initialization • Eliminate ~4% CPU overhead in SecurityManager.checkAccess logging • Simplify authentication check logic by inverting condition • Add startup warning in Settings.ts alongside other config warnings
Diagram
flowchart LR
A["SecurityManager.checkAccess<br/>per-message"] -->|removed| B["console.warn<br/>~4% CPU cost"]
C["Settings.ts<br/>startup init"] -->|added| D["logger.warn<br/>one-time warning"]
E["loadTest bypass<br/>logic"] -->|unchanged| F["Silent short-circuit"]
File Changes
1. src/node/db/SecurityManager.ts
Performance optimization +7/-4
Remove per-message loadTest warning from checkAccess
• Removed per-message console.warn call that fired on every checkAccess invocation • Simplified authentication check by inverting condition logic (if !settings.loadTest && settings.requireAuthentication) • Added detailed comment explaining the performance issue and rationale for the change • Preserved loadTest short-circuit behavior without logging overhead
2. src/node/utils/Settings.ts
✨ Enhancement +6/-0
Add startup warning for loadTest configuration
• Added one-time startup warning when settings.loadTest is enabled • Warning placed in reloadSettings initialization alongside other config-time warnings • Includes production safety notice about authentication/authorization bypass • Eliminates need for per-request logging
Code Review by Qodo
🐞 Bugs (0) 📘 Rule violations (1) 📎 Requirement gaps (0)
1. settings.loadTest block misindented 📘 Rule violation ⚙ Maintainability
Description
New code in Settings.ts uses 4+ space indentation rather than the required 2-space indentation. This introduces formatting inconsistency and violates the no-tabs/2-space indentation standard for modified lines.
Code
src/node/utils/Settings.ts[R1196-1200]+ if (settings.loadTest) { + logger.warn( + 'settings.loadTest is true: socket.io authentication and authorization checks ' + + 'will be bypassed for every connection. Do NOT enable this in production.'); + }
Evidence
PR Compliance ID 3 requires spaces-only with 2-space indentation for all modified/added lines. The added if (settings.loadTest) { block and its wrapped logger.warn(...) lines are indented with more than 2 spaces in the modified region cited below.
src/node/utils/Settings.ts[1196-1200]
Best Practice: Repository guidelines
Agent prompt
The issue below was found during a code review. Follow the provided context and guidance below and implement a solution ## Issue description Modified lines in `src/node/utils/Settings.ts` use indentation that is not 2-space (e.g., the added `if (settings.loadTest)` block is indented with 4+ spaces). The compliance checklist requires spaces-only and 2-space indentation for all changed/added code. ## Issue Context This PR adds a startup `logger.warn(...)` when `settings.loadTest` is enabled. The logic is fine, but the indentation of the newly added lines does not match the 2-space requirement. ## Fix Focus Areas - src/node/utils/Settings.ts[1196-1200]
i Copy this prompt and use it to remediate the issue with your preferred AI generation tools
2. (削除) LoadTest warning scope wrong (削除ここまで) ✓ Resolved 🐞 Bug ◔ Observability
Description
The new Settings.reloadSettings() warning says only socket.io authn/authz is bypassed, but settings.loadTest short-circuits SecurityManager.checkAccess() which is used by both socket.io and HTTP handlers. This warning therefore understates the security-impact surface area of enabling loadTest.
Code
src/node/utils/Settings.ts[R1196-1200]+ if (settings.loadTest) { + logger.warn( + 'settings.loadTest is true: socket.io authentication and authorization checks ' + + 'will be bypassed for every connection. Do NOT enable this in production.'); + }
Evidence
The warning text is socket.io-specific, but settings.loadTest gates enforcement in SecurityManager.checkAccess(), and that function is called from both socket.io handling (PadMessageHandler) and HTTP endpoints (padaccess, importexport).
src/node/utils/Settings.ts[1196-1200]
src/node/db/SecurityManager.ts[60-101]
src/node/handler/PadMessageHandler.ts[496-508]
src/node/padaccess.ts[6-14]
src/node/hooks/express/importexport.ts[77-92]
Agent prompt
The issue below was found during a code review. Follow the provided context and guidance below and implement a solution ## Issue description The warning message for `settings.loadTest` currently claims that only socket.io authentication/authorization checks are bypassed. In reality, `settings.loadTest` affects `SecurityManager.checkAccess()`, which is used by both socket.io message handling and HTTP routes (e.g., pad access and import/export). ### Issue Context Accurate operator-facing warnings matter for a security-bypass setting like `loadTest`. The current wording can mislead an operator into thinking the bypass is limited to socket.io. ### Fix Focus Areas - src/node/utils/Settings.ts[1196-1200] - src/node/db/SecurityManager.ts[60-101] - src/node/handler/PadMessageHandler.ts[496-508] - src/node/padaccess.ts[6-14] - src/node/hooks/express/importexport.ts[77-92] ### Suggested fix Adjust the warning string to reflect the real scope, e.g.: - "settings.loadTest is true: authentication/authorization checks in SecurityManager.checkAccess() will be bypassed (affects both HTTP and socket.io). Do NOT enable this in production." Optionally mention that it applies to pad access checks generally, not a single transport.
i Copy this prompt and use it to remediate the issue with your preferred AI generation tools
3. (削除) Misleading startup-only comment (削除ここまで) ✓ Resolved 🐞 Bug ⚙ Maintainability
Description
SecurityManager.checkAccess() now states the loadTest warning "fires once at startup", but the warning is emitted from reloadSettings(), which is also called on admin restart and after plugin install. This inaccurate comment can mislead future maintainers about when the warning will appear.
Code
src/node/db/SecurityManager.ts[R78-80]+ // settings.loadTest just short-circuits authn/authz; the user-facing + // warning about this configuration choice fires once at startup, not + // per request (see Settings.ts). Re-logging it here was costing
Evidence
The comment explicitly claims the warning fires only at startup, but the warning is implemented inside reloadSettings(), and reloadSettings() is invoked from runtime code paths (admin restart and plugin install completion).
src/node/db/SecurityManager.ts[77-85]
src/node/utils/Settings.ts[1187-1201]
src/node/hooks/express/adminsettings.ts[395-401]
src/static/js/pluginfw/installer.ts[29-35]
Agent prompt
The issue below was found during a code review. Follow the provided context and guidance below and implement a solution ## Issue description A comment in `SecurityManager.checkAccess()` claims the `settings.loadTest` warning "fires once at startup", but the warning is logged from `reloadSettings()`, which can be called multiple times during runtime (admin restart, plugin operations). This makes the comment factually incorrect. ### Issue Context The PR moved the warning from the per-message hot path to settings reload time, which is good. However, the comment now over-specifies behavior that isn’t true. ### Fix Focus Areas - src/node/db/SecurityManager.ts[77-85] - src/node/utils/Settings.ts[1192-1201] - src/node/hooks/express/adminsettings.ts[395-401] - src/static/js/pluginfw/installer.ts[29-35] ### Suggested fix Update the comment to something like: "the warning is logged during settings load/reload (see Settings.ts), not per request" (or remove the timing claim entirely).
i Copy this prompt and use it to remediate the issue with your preferred AI generation tools
JohnMcLear
commented
May 16, 2026
N=3 measured impactThree perf-branch runs (25959515488, 25959516741, 25959517823) vs the same three develop baselines used to score #7775 — `authors=100..500:step=50:dwell=8s:warmup=2s`:
* step 350 develop raw p95 triples [35, 41.6, 41.8] vs #7776 [37.1, 37.9, 38.8] — develop's 39 is a single-run dip; #7776's distribution is tighter (every run between 37-39) which the median doesn't show. The CPU% gain at this step (-8.9%) is the cleanest direction signal. Summary:
Pairs cleanly with #7775 (which fixes a different log4js entry path). Both should land. |
Three combined-branch runs (perf/dive-combined = #7776 cherry-picked onto #7775 base; runs 25960003164/25960004223/25960005248) vs the same three develop baselines: -12% to -20% CPU% across all 9 sweep steps, with the p95 cliff effectively moving from ~400 to ~500 authors (at step 400, two of three combined runs land below the cliff at 45ms and 112ms p95 vs develop [1758, 2275, 2463]). Adds: - Lever 10 section for #7776 with its own N=3 numbers (-3.6 to -8.9% alone). - "Stacking" section showing super-additive interaction. - Local vCPU experiment showing the cliff is single-event-loop-bound, not total-CPU-bound: 4-core and 8-core pinned SUTs hit the same cliff at the same step. - Updated TL;DR, Recommendation order (merge both #7775+#7776 first), and "Where to take this next" with worker-thread offload as the smallest next architectural step. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
JohnMcLear
commented
May 16, 2026
#7775 + #7776 stacked — N=3 combined measurementI cherry-picked #7775 onto #7776 (branch
The stacked impact (-12% to -20% CPU%) is well above the sum of the individual gains. Both fixes remove call sites feeding the same log4js cluster-mode dispatch chain ( Latency: cliff has effectively moved past step 400. Raw p95 triples:
At step 400, two of three combined runs land below the cliff entirely. Recommend landing these two together to capture the full effect. |
Post-#7775/#7776 profile shows applyToAText splits cleanly: - applyToText (Changeset.ts:404) is pure (cs, text) -> text; trivially offloadable to a worker via worker_threads structured-clone postMessage. - applyToAttribution (Changeset.ts:684) mutates AttributePool; not trivially offloadable. Document the obvious first-pass design (run them in parallel via Promise.all inside applyToAText) and the realistic estimate (~6-8% CPU moved off the main event loop). putAttrib is only 0.26% in the post-fix profile, confirming the bulk of applyToAText's cost is in the string-manipulation half. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Three issues flagged: 1. Indentation: outdented the continuation lines inside the new `if (settings.loadTest)` block from 10 spaces to 8 (one level from `logger.warn(`), matching 2-space indent rule for added code. 2. Warning scope: the original wording said only socket.io authn/authz is bypassed, but settings.loadTest short-circuits SecurityManager.checkAccess() which is called from both HTTP (padaccess, importexport) and socket.io (PadMessageHandler) paths. Reword to "SecurityManager.checkAccess() will bypass authentication and authorization for both HTTP and socket.io requests". 3. Misleading "fires once at startup" comment in SecurityManager.ts: the warning is logged from Settings.ts reloadSettings(), which is also called on admin restart and plugin install. Rephrase to "logged from Settings.ts during settings load/reload, not on every request". All three issues are accurate. No behaviour change for the fix itself; only comment + warning text. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
JohnMcLear
commented
May 16, 2026
Addressed all three Qodo issues in afb3a4a:
-
Indentation (PR Compliance ID 3) — outdented the continuation lines from 10 spaces to 8 (one level from
logger.warn(), matching 2-space-per-indent convention for added code. -
LoadTest warning scope — reworded to "SecurityManager.checkAccess() will bypass authentication and authorization for both HTTP and socket.io requests". The original wording understated the surface — checkAccess is also called from
padaccess.tsandimportexport.ts. -
Misleading "fires once at startup" comment — rephrased to "logged from Settings.ts during settings load/reload, not on every request". Correct: reloadSettings() is also called on admin restart and plugin install (per Qodo's references to adminsettings.ts and installer.ts).
71 backend tests pass (sessionsAndGroups + socketio).
JohnMcLear
commented
May 16, 2026
Re Qodo's remaining issue #1 (indent on Settings.ts:1196-1200):
The surrounding reloadSettings() body uses 4-space indent throughout (look at the unchanged context lines logger.warn(\"loglevel: \" + ...) at 1192-1194, the padOptions block at 1116-1136, etc). My new if (settings.loadTest) { ... } block matches the local 4-space convention. Re-indenting just my five lines to 2 would create a worse visual problem: the new if body would sit less indented than its sibling statements in the same function.
The .editorconfig does declare indent_size = 2, but eslint is not currently enforcing it (the v9 config migration hasn't landed in this repo) and the file as a whole is already inconsistent. Reformatting the whole reloadSettings() function to 2-space is real cleanup work that doesn't belong in a perf PR.
Leaving as-is to match local convention.
Add a "Roadmap for future effort" section ahead of Reproducing, ranking the next concrete options by impact-per-time-spent. Tier 1 (mechanical / <1 day each): - merge ready perf PRs (#7775+#7776+#7774) - implement #7780 room-broadcast fan-out - additional post-fix profile pass Tier 2 (medium, real cliff moves): - selective fan-out / viewport-based broadcast (~2 weeks; cliff ~500 → 1000-1500) - per-pad worker isolation PoC (~1-2 weeks PoC, 1-2 months prod) Tier 3 (large bets): - sticky-session cluster mode (~2-4 weeks PoC) - CRDT migration (months; anti-recommended) Tier 4 (operational): - production telemetry hookup (~3-5 days) - nightly dive in CI (~1 day) Records the recommended sequence (Tier 1.2 → Tier 2.4) so the next person picking this up doesn't need to re-derive it. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Summary
A fresh CPU profile of the dive SUT (etherpad-load-test workflow run 25957515210, against open PR #7775's branch to remove the throw-cascade noise) revealed that ~4% of total process CPU was spent in log4js inside
SecurityManager.checkAccess— and it wasn't from the throw chain at all. Tracing the actual log call exposes this line:```ts
// SecurityManager.checkAccess, line 78-81
if (settings.loadTest) {
console.warn(
'bypassing socket.io authentication and authorization checks due to settings.loadTest');
}
```
When `settings.loadTest` is true (used by the dive harness, by some local dev rigs, and by anyone benchmarking), this `console.warn` fires on every `checkAccess` call — once per inbound socket.io message. With `log4js.replaceConsole` + cluster-mode dispatch (default), each warning allocates a LogEvent, formats it, and walks the `sendToListeners` → `sendLogEventToAppender` chain. The profile attributes ~4% of total CPU to that path.
`settings.loadTest` is a configuration choice, not a per-request condition. Move the warning to startup (Settings.ts init, next to the other config-time warnings), and drop the per-message branch. The loadTest short-circuit (bypassing the `else if (settings.requireAuthentication)` block) still applies — just silently.
Profile evidence
Inverted-caller analysis of `log4js.Logger.` in the perf-branch profile (CPU.20260516.083843.26230001.cpuprofile, 100→400 author sweep, ~103s wall, 65% on-CPU):
```
4.08% exports.checkAccess [src/node/db/SecurityManager.ts]
0.19% _getLocked [nm/ueberdb2]
0.19% _setLocked [nm/ueberdb2]
0.09% handleRequest [nm/router/lib/layer.js]
0.07% (anon) [src/node/handler/SocketIORouter.ts]
```
After PR #7775 removed the `getSessionInfo` throw cascade, this number was unchanged, which is what surfaced the real root cause.
Test plan
Relationship to #7775
Independent. #7775 removes the throw-as-control-flow pattern (CustomError construction is real CPU, ~1.8%); this PR removes the per-message warning logging (~4% in dive measurements with `loadTest: true`). Both should land. Together they hit the actionable parts of the per-message logger cost the profile flagged.