Skip to content

Commit 9e3af10

Browse files
robacourtclaude
andauthored
Add regression test for subquery materializer multi-chunk log replay (bug 4) (#4670)
## Summary Adds a deterministic regression test for **bug 4** from the restore-from-file bug triage in #4648 (bug doc: `packages/sync-service/bugs.md`). This is a **test-only** change. Bug 4's production fix — the two main-log short-circuits in `Materializer.read_history_up_to_subscribed/2` — already shipped alongside the bug 1 fix in #4651; it just lacked dedicated regression coverage. ## Problem (bug 4) On startup recovery the subquery materializer replays the source shape's persisted history (snapshot + main log) up to its subscribed offset. `Storage.get_log_stream/3` returns one chunk per call for the **snapshot**, but returns the **entire** requested range for the **main log** in a single call. When the source shape's main log spans more than one chunk, a replay loop that keeps advancing through chunk boundaries past the first main-log chunk re-reads main-log entries it has already applied. Re-applying a `NewRecord` for an existing key raises `Key ... already exists`, crashing the materializer (and taking the dependent shape's consumer down with it → 409 must-refetch on the next poll). ## Solution / coverage The fix (already merged in #4651) stops iterating as soon as the read steps into the main log. This PR adds the missing regression test: `test/electric/shapes/consumer/materializer_test.exs` → `"does not re-read main-log entries when the main log spans multiple chunks"` - Sets `chunk_bytes_threshold: 10` to force the source shape's main log across ≥2 chunks (asserts the first main-log chunk ends strictly before the subscribed offset). - Persists two `NewRecord` inserts in separate main-log chunks, subscribes past both, and asserts startup replay yields the correct `value_counts` exactly once. ## Test Plan - [x] Passes with the fix in place (`59 tests, 0 failures` in the file). - [x] Fails without the fix: reverting the short-circuits makes the test crash with `** (RuntimeError) Key "public"."test_table"/"3" already exists` from `read_history_up_to_subscribed/2` — confirming it's a genuine failing-first regression test. - [x] `mix format --check-formatted` clean. ## Notes An end-to-end variant in `oracle_restore_test.exs` was prototyped but not included: it does trigger the crash, but the failure self-heals via a client refetch that re-syncs to the oracle, so it passes with and without the fix — false-confidence coverage. The deterministic unit test is the reliable regression guard. --- Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent ec98959 commit 9e3af10

1 file changed

Lines changed: 87 additions & 0 deletions

File tree

packages/sync-service/test/electric/shapes/consumer/materializer_test.exs

Lines changed: 87 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1437,6 +1437,93 @@ defmodule Electric.Shapes.Consumer.MaterializerTest do
14371437
# iteration fix guarantees the UPDATE is replayed.
14381438
assert Materializer.get_link_values(mat_ctx) == MapSet.new([99])
14391439
end
1440+
1441+
# When the source shape's persisted main log spans MORE than one chunk,
1442+
# `Storage.get_log_stream/3` returns the *entire* main-log range in a
1443+
# single call (chunking only applies to the snapshot). Startup replay must
1444+
# therefore stop iterating as soon as it steps into the main log:
1445+
# continuing to advance through chunk boundaries would re-read main-log
1446+
# entries it has already applied, and re-applying a `NewRecord` for a key
1447+
# that already exists raises "Key already exists", crashing the
1448+
# materializer and the dependent shape's consumer. This test guards that
1449+
# each persisted entry is applied exactly once.
1450+
@tag with_pure_file_storage_opts: [chunk_bytes_threshold: 10]
1451+
test "does not re-read main-log entries when the main log spans multiple chunks", ctx do
1452+
shape_handle = "multichunk-test-#{System.unique_integer()}"
1453+
1454+
storage = Storage.for_shape(shape_handle, ctx.storage)
1455+
Storage.start_link(storage)
1456+
writer = Storage.init_writer!(storage, @shape)
1457+
Storage.mark_snapshot_as_started(storage)
1458+
1459+
# Snapshot with one row at value=10.
1460+
Storage.make_new_snapshot!(
1461+
make_snapshot_data([%Changes.NewRecord{record: %{"id" => "1", "value" => "10"}}]),
1462+
storage
1463+
)
1464+
1465+
# Two main-log INSERTs persisted before the materializer subscribes.
1466+
# With a tiny `chunk_bytes_threshold` each lands in its own main-log
1467+
# chunk, so the main log spans more than one chunk — the condition under
1468+
# which a second read of the same range would re-apply the insert for
1469+
# key "3".
1470+
offset_2 = LogOffset.new(100, 0)
1471+
offset_3 = LogOffset.new(200, 0)
1472+
1473+
writer =
1474+
Storage.append_to_log!(
1475+
[
1476+
{offset_2, ~s|"public"."test_table"/"2"|, :insert,
1477+
~s|{"key":"\\"public\\".\\"test_table\\"/\\"2\\"","value":{"id":"2","value":"20"},"headers":{"operation":"insert"}}|}
1478+
],
1479+
writer
1480+
)
1481+
1482+
writer =
1483+
Storage.append_to_log!(
1484+
[
1485+
{offset_3, ~s|"public"."test_table"/"3"|, :insert,
1486+
~s|{"key":"\\"public\\".\\"test_table\\"/\\"3\\"","value":{"id":"3","value":"30"},"headers":{"operation":"insert"}}|}
1487+
],
1488+
writer
1489+
)
1490+
1491+
Storage.hibernate(writer)
1492+
1493+
# Sanity check: the main log really does span more than one chunk. The
1494+
# first main-log chunk (the one reached from the end of the snapshot)
1495+
# must end strictly before the last persisted offset. Without this, a
1496+
# single read would cover the whole main log and the multi-chunk case
1497+
# under test wouldn't be exercised.
1498+
first_main_chunk_end =
1499+
Storage.get_chunk_end_log_offset(LogOffset.last_before_real_offsets(), storage)
1500+
1501+
assert not is_nil(first_main_chunk_end)
1502+
assert LogOffset.compare(first_main_chunk_end, offset_3) == :lt
1503+
1504+
ConsumerRegistry.register_consumer(self(), shape_handle, ctx.stack_id)
1505+
1506+
{:ok, _pid} =
1507+
Materializer.start_link(%{
1508+
stack_id: ctx.stack_id,
1509+
shape_handle: shape_handle,
1510+
storage: ctx.storage,
1511+
columns: ["value"],
1512+
materialized_type: {:array, :int8}
1513+
})
1514+
1515+
respond_to_call(:await_snapshot_start, :started)
1516+
# Subscribe past both persisted INSERTs so startup replay walks the
1517+
# snapshot and the whole multi-chunk main log.
1518+
respond_to_call(:subscribe_materializer, {:ok, offset_3})
1519+
1520+
mat_ctx = %{stack_id: ctx.stack_id, shape_handle: shape_handle}
1521+
assert Materializer.wait_until_ready(mat_ctx) == :ok
1522+
1523+
# The snapshot value and both persisted INSERTs must each be applied
1524+
# exactly once.
1525+
assert Materializer.get_link_values(mat_ctx) == MapSet.new([10, 20, 30])
1526+
end
14401527
end
14411528

14421529
describe "startup race condition handling" do

0 commit comments

Comments
 (0)