xinnyuli commented on issue #12382: URL: https://github.com/apache/seatunnel/issues/12382#issuecomment-5907139938
> Thanks [@xinnyuli](https://github.com/xinnyuli) — this is exactly the evidence that was asked for, and the uninstrumented control settles the most important open question: the `expected: <1> but was: <0>` delivery failure reproduces on both [c7304ac](https://github.com/apache/seatunnel/commit/c7304ace6e18d350314e92480df1fd3c0962f1f2) and [4c874e2](https://github.com/apache/seatunnel/commit/4c874e2a4061aea9d5db65e74edeb211b498fe27) with the untouched upstream test under load, so the loss is not an artifact of the tracing agent. Keeping the committed-LSN setup timeout out of the denominator and reporting the reached count per row is also the right way to record this. > > A few notes on how I read the table: > > * 2/30 and 1/30 uninstrumented on baseline and dev means the row loss is now reproducible, if rare, and it is present on both revisions. That says the behaviour predates the dev revision rather than being introduced by it, but as you point out, the sample is too small to say anything about the delta between the groups or about whether tracing shifts the rate. > * The no-load result (0/29 per revision) staying clean is consistent with a timing window that only opens under contention, which fits the original scheduled failure better than a deterministic bug would. > > Your last comment appears to have been cut off at "Since row loss is now r" — could you repost the remainder? I would like to see what you were proposing before agreeing on the next step. > > Assuming the rest goes where I expect, the next step within this investigation is the test-only correlation trace that was previously gated on reproducibility: for each failing run, capture (a) whether the reader ever emitted `id=15` after reattachment, (b) the checkpoint/committed-LSN advancement relative to that row's WAL position, and (c) whether the JDBC sink received it. Please keep that on the same two revisions, keep the load matrix recorded separately from the no-load runs, and keep reporting reached/not-reached alongside row-missing. Still no production tracing or fix PR at this stage — once the trace shows which stage drops the row, we can talk about the fix. Sure! I'm so sorry, the end of my last comment got cut off. Here is the rest, plus a new run that answers (a)-(c). (a)/(c) From the traced stress runs (agent on): in all 7 missing-row runs, no id=15 record reached the Debezium receiver after reattachment, so the reader never emitted it and the JDBC sink never received it. In all 52 passing runs the same trace follows id=15 through receiver -> emitter -> sink write. (b) In 6 of those 7 runs the committed LSN moved from the restored value to exactly +312 bytes and stayed there for the full 3 minutes. 312 bytes is the size of the id=15 transaction (measured in passing runs), so the committed LSN moved past the row without the row being emitted. The 7th run stopped at +8144, which fits the same pattern but is less direct. Why the reader never saw it: the drop happens inside Debezium 1.9.8's WAL resume search (PostgresStreamingChangeEventSource.execute -> WalPositionLocator), which SeaTunnel's PostgresWalFetchTask calls directly. 1. The restored offset has lsn_proc == lsn_commit. It was written by a heartbeat, so it is the END LSN of the last COMMIT. 2. Debezium treats it as "last processed change LSN", opens one replication connection to search for the resume point, then reconnects (the second START_REPLICATION ~0.5s later in the Postgres log). 3. The end of a commit record is where the next WAL record starts. When the id=15 INSERT is the very next record, its LSN equals the stored value, so WalPositionLocator treats it as already processed and moves the resume position past it. 4. On the replayed stream, skipMessage filters id=15's BEGIN/INSERT as "already processed", the offset moves on, and nothing errors. To check this directly I ran the untouched upstream test (no agent) with stress-ng, Java 11, same two revisions, and only raised WalPositionLocator / AbstractMessageDecoder / PostgresStreamingChangeEventSource to INFO in the test log4j2.properties (it sets io.debezium.connector to WARN): - baseline c7304ace: 1/30 missing; dev 4c874e2a: 1/29 missing (one setup timeout, not counted). - In the missing-row run I looked at in detail, the stored last commit LSN and last change LSN are both 0/222A6B0, the first LSN received on restart is also 0/222A6B0, and the log says "received LSN 0/222A6B0 identified as already processed" (twice). The resume position then becomes 0/222A7E8, i.e. stored + 312 bytes, which matches the size of the id=15 transaction. - In the same run, the two earlier restores had a first LSN different from the stored one and resumed normally ("Will restart from ... start of the first unprocessed transaction"). - The other missing-row run shows the same pattern (resume - stored = 312). None of the 57 passing runs shows it. In passing runs other WAL (56-408 bytes) sits between the stored LSN and id=15, so there is no collision. That would also explain why it only shows up under load. Caveats: upstream Debezium main has a guard for what looks like the same false match in WalPositionLocator (the comment references debezium/dbz#76). Its comment mentions PG 17+, while this test uses debezium/postgres:11 with decoderbufs, so I can't yet say it is exactly the same case, and I haven't checked which release contains it. The counts are also small (2 missing-row runs with the Debezium logs on). No production tracing or fix PR from me. If it helps before discussing a fix, I can write a deterministic test that puts the id=15 INSERT right at the restored LSN, so it fails every time instead of ~3% under load. Runs and raw logs: https://github.com/xinnyuli/seatunnel-12382-repro/actions/runs/36598036888 -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
