SPOC-551: add spock.log_verbosity and spock.apply_change_logging GUCs#477
SPOC-551: add spock.log_verbosity and spock.apply_change_logging GUCs#477ibrarahmad wants to merge 1 commit into
Conversation
log_verbosity (normal|verbose) promotes spock DEBUG1/DEBUG2 to LOG. apply_change_logging (none|key_only|verbose) emits per-change JSON from the apply worker: action/schema/table/pk/origin/commit_ts in key_only, plus old/new row data in verbose. DDL is logged in both non-none modes. Both GUCs are PGC_SUSET (SET / SIGHUP reload). TAP coverage in tests/tap/t/044_apply_change_logging.pl - 24/24.
📝 WalkthroughWalkthroughThis PR introduces structured JSON logging for the Spock apply worker, enabling operators to observe replicated changes. It adds two GUCs controlling log verbosity and detail level, implements JSON serialization helpers and logging entry points, integrates change logging into apply operations, refines debug message routing, and provides comprehensive test coverage. ChangesSpock Apply Worker Change Logging
Poem
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches📝 Generate docstrings
🧪 Generate unit tests (beta)
⚔️ Resolve merge conflicts
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 |
Up to standards ✅🟢 Issues
|
| Category | Results |
|---|---|
| Complexity | 2 medium |
🟢 Metrics 42 complexity · 0 duplication
Metric Results Complexity 42 Duplication 0
NEW Get contextual insights on your PRs based on Codacy's metrics, along with PR and Jira context, without leaving GitHub. Enable AI reviewer
TIP This summary will be updated as you push new changes.
![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 (1)
tests/tap/t/044_apply_change_logging.pl (1)
20-30: ⚡ Quick winAdd a test case for skipped DML in
TRANSDISCARD/SUB_DISABLEmodes.Current coverage is strong for normal apply flow, but it doesn’t assert that skipped DML in exception replay modes does not emit apply-change records. Adding this would close a high-risk gap in logging correctness.
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@tests/tap/t/044_apply_change_logging.pl` around lines 20 - 30, Add a new test in the same TAP file that verifies skipped DML under the TRANSDISCARD and SUB_DISABLE replay modes does not emit apply-change JSON log records: set apply_change_logging to key_only (and repeat for verbose), configure publisher/subscriber, perform DML on the publisher that will be skipped on the subscriber by triggering TRANSDISCARD and SUB_DISABLE replay behavior, capture the subscriber server logs (same log-capture helpers used elsewhere in this test file), and assert that no apply-change JSON lines (those containing action/schema/table/pk and, for verbose, new row data) are present for the skipped DML; name the test case clearly (e.g., "skipped DML in TRANSDISCARD/SUB_DISABLE produces no apply_change_logging records") so it’s easy to find.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@src/spock_apply.c`:
- Around line 1414-1416: The apply-change log is emitted even when DML was
intentionally skipped under exception-replay modes TRANSDISCARD/SUB_DISABLE;
update the three spots that call spock_log_apply_change (the INSERT block with
newtup, the UPDATE block with oldtup/newtup, and the DELETE block with oldtup)
to only call spock_log_apply_change when the operation both did not fail and was
actually applied — i.e., change the guard from if (!failed) to if (!failed &&
!<skip-dml-flag>), where <skip-dml-flag> checks the current exception replay
mode (TRANSDISCARD or SUB_DISABLE) or otherwise detects that DML was skipped;
use the existing symbols for those modes so the check reflects the code’s
exception replay state and ensures no “applied change” log is produced for
skipped operations.
---
Nitpick comments:
In `@tests/tap/t/044_apply_change_logging.pl`:
- Around line 20-30: Add a new test in the same TAP file that verifies skipped
DML under the TRANSDISCARD and SUB_DISABLE replay modes does not emit
apply-change JSON log records: set apply_change_logging to key_only (and repeat
for verbose), configure publisher/subscriber, perform DML on the publisher that
will be skipped on the subscriber by triggering TRANSDISCARD and SUB_DISABLE
replay behavior, capture the subscriber server logs (same log-capture helpers
used elsewhere in this test file), and assert that no apply-change JSON lines
(those containing action/schema/table/pk and, for verbose, new row data) are
present for the skipped DML; name the test case clearly (e.g., "skipped DML in
TRANSDISCARD/SUB_DISABLE produces no apply_change_logging records") so it’s easy
to find.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: ebbbe842-5466-4b4d-86ca-e2caf912cda8
📒 Files selected for processing (10)
include/spock.hinclude/spock_change_log.hsrc/spock.csrc/spock_apply.csrc/spock_change_log.csrc/spock_common.csrc/spock_dependency.csrc/spock_sync.ctests/tap/scheduletests/tap/t/044_apply_change_logging.pl
| if (!failed) | ||
| spock_log_apply_change("INSERT", rel, NULL, &newtup, | ||
| remote_origin_name); |
There was a problem hiding this comment.
Prevent false “applied change” logs for skipped DML in exception replay modes.
In TRANSDISCARD/SUB_DISABLE, DML is intentionally skipped but failed remains false, so these blocks still emit spock_log_apply_change(...). That produces incorrect apply-change logs for operations never applied.
Proposed fix
- if (!failed)
+ if (!failed &&
+ !(MyApplyWorker->use_try_block &&
+ (exception_behaviour == TRANSDISCARD ||
+ exception_behaviour == SUB_DISABLE)))
spock_log_apply_change("INSERT", rel, NULL, &newtup,
remote_origin_name);- if (!failed)
+ if (!failed &&
+ !(MyApplyWorker->use_try_block &&
+ (exception_behaviour == TRANSDISCARD ||
+ exception_behaviour == SUB_DISABLE)))
spock_log_apply_change("UPDATE", rel,
hasoldtup ? &oldtup : NULL, &newtup,
remote_origin_name);- if (!failed)
+ if (!failed &&
+ !(MyApplyWorker->use_try_block &&
+ (exception_behaviour == TRANSDISCARD ||
+ exception_behaviour == SUB_DISABLE)))
spock_log_apply_change("DELETE", rel, &oldtup, NULL,
remote_origin_name);Also applies to: 1584-1587, 1716-1718
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
In `@src/spock_apply.c` around lines 1414 - 1416, The apply-change log is emitted
even when DML was intentionally skipped under exception-replay modes
TRANSDISCARD/SUB_DISABLE; update the three spots that call
spock_log_apply_change (the INSERT block with newtup, the UPDATE block with
oldtup/newtup, and the DELETE block with oldtup) to only call
spock_log_apply_change when the operation both did not fail and was actually
applied — i.e., change the guard from if (!failed) to if (!failed &&
!<skip-dml-flag>), where <skip-dml-flag> checks the current exception replay
mode (TRANSDISCARD or SUB_DISABLE) or otherwise detects that DML was skipped;
use the existing symbols for those modes so the check reflects the code’s
exception replay state and ensures no “applied change” log is produced for
skipped operations.
| DefineCustomEnumVariable("spock.log_verbosity", | ||
| gettext_noop("Sets the verbosity of spock-specific log output."), | ||
| gettext_noop("When 'verbose', spock's own DEBUG1 and DEBUG2 messages are " | ||
| "promoted to LOG level so they appear in standard server logs " | ||
| "without changing log_min_messages globally."), | ||
| &spock_log_verbosity, | ||
| SPOCK_LOG_VERBOSITY_NORMAL, | ||
| log_verbosity_options, | ||
| PGC_SUSET, 0, | ||
| NULL, NULL, NULL); | ||
|
|
||
| DefineCustomEnumVariable("spock.apply_change_logging", | ||
| gettext_noop("Controls JSON logging of changes applied by the apply worker."), |
There was a problem hiding this comment.
I don't think we need both spock.log_verbosity and spock.apply_change_logging. A single spock.debug_log_level using the stock server_message_level_options enum should be sufficient: increasing the DEBUG level increases verbosity exactly like Postgres itself.
That also removes the need for the new SPOCK_DEBUG1/SPOCK_DEBUG2 macros — every existing ereport(DEBUG1/2, …) is already gated by log_min_messages, so the GUC simply controls the level at which spock's own debug output is emitted.
| if (!failed) | ||
| spock_log_apply_change("UPDATE", rel, | ||
| hasoldtup ? &oldtup : NULL, &newtup, |
There was a problem hiding this comment.
Should the change-log record really be gated by !failed? When user turns this on they almost certainly want to see the conflict and exception cases — those are the interesting ones. As written, it silently drops exactly the records you'd enable it to capture. I'd either always emit (with "incoming"|"applied"|"conflict"|"skipped" field, can be a generic string) or hook into spock_report_conflict()/log_insert_exception.
Same comment applies to the DDL path in handle_sql — it logs before execution, so a failed DDL still produces an "action":"DDL" line that looks applied.
| static void | ||
| append_json_string(StringInfo buf, const char *str) | ||
| { | ||
| appendStringInfoChar(buf, '"'); |
There was a problem hiding this comment.
src/spock_jsonb_utils.c already has most of the tuple->JSON functionality needed here (and already makes use of escape_json()); it should be enhanced where it falls short rather than duplicated.
2 participants
log_verbosity (normal|verbose) promotes spock DEBUG1/DEBUG2 to LOG. apply_change_logging (none|key_only|verbose) emits per-change JSON from the apply worker: action/schema/table/pk/origin/commit_ts in key_only, plus old/new row data in verbose. DDL is logged in both non-none modes. Both GUCs are PGC_SUSET (SET / SIGHUP reload).
TAP coverage in tests/tap/t/044_apply_change_logging.pl - 24/24.