SYM-7915: Prevent initial loads deadlocks due to a JVM restart mid-extract - #994
SYM-7915: Prevent initial loads deadlocks due to a JVM restart mid-extract#994gp510 wants to merge 2 commits into
Conversation
… mid-extract An initial load whose extract is interrupted by a JVM restart comes back permanently stuck. sym_extract_request reads OK with extracted_rows=0 while its batches are still RQ. Every extraction selector filters on NE so nothing re-extracts it, extractBatch refuses to deliver an RQ batch, nothing reconciles the two, and nothing surfaces it. The only symptom in the product is a pair of INFO log lines, so the console shows an ACTIVE pipeline making no progress and it is indistinguishable from a slow load. At the reporting site it ran three days, was never recovered, and the load had to be discarded. The state comes from one place. extractOutgoingBatch marked the entire request -- all of its batches -- OK from a single batch's extract_row_count and extract_millis, with no check that anything was actually extracted and no check that the rest of the range had finished. A batch that skipped extraction because it was already extracted contributes a zero row count and a near-zero duration, which is exactly the row observed. Three layers: - Guard. isExtractRequestComplete gates the status write. When the request is not complete the statistics accumulate through a new incremental statement instead, so progress stays visible without claiming completion. - Reconciler. recoverStuckExtractRequests returns such requests to NE, called from queueWork inside the existing cluster lock, which InitialLoadExtractorJob already drives every 10s. That covers startup for free, and the NE requests it produces are picked up later in the same invocation. A startup-only check would not have helped the reporting site, whose node ran three days in this state. - restartExtractRequest now also zeroes extracted_rows / extracted_millis, which it previously left behind, so a recovered request stops reporting counters from the run that was interrupted. Detection is exact rather than heuristic. MultiBatchStagingWriter.close() advances every remaining batch in the range, so a finished extract leaves none at RQ. A request at OK with an RQ batch in its range is therefore an impossible state, not a healthy in-flight one, which is what makes both the guard and the reconciler free of false positives against a running extract. Requests whose range contains already-delivered batches are deliberately NOT restarted automatically. restartExtractRequest flips the whole range back to RQ through updateOutgoingBatchStatusSql, which carries no status predicate, so it would re-send rows already committed at the target -- and the target's own record of them can be missing, which is the data-integrity half of this defect. Those are reported at ERROR every pass with the recovery choices and require force. initial.load.extract.request.recovery.enabled (default true) and ...threshold.ms (default 300000, only to avoid racing an in-flight status write). recoverStuckExtractRequests is on IDataExtractorService so an operator surface can bind it; DataExtractorService is the only implementer and FileSyncExtractorService inherits it, and there is no PRO implementer, so nothing else has to change. 7 new tests pinning the recovery statements. 1111 tests pass across symmetric-core, symmetric-db, symmetric-jdbc and symmetric-io with 0 failures. The end-to-end kill-and-recover path needs a real database and is not covered here; it is on the ticket as manual QA. Also found while reading and deliberately not folded in: sym_extract_request rows are inserted as LS and flipped LS->NE by DataService, and nothing recovers an LS request either, so a kill during load setup strands a load the same way. The reconciler is the natural home for it, but it is a separate defect and should be its own ticket. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…dless work Quality pass, no behaviour change. All 781 tests in :symmetric-core still pass. Two real costs, both found by tracing call frequency: - isExtractRequestComplete ran a count(*) per delivered load batch on the pull path. The answer is only ever compared to zero, but a count has to visit every batch in the request's range, so across a load split into N batches the cost grew with N squared, on the same table the extract job is writing to. It now selects one row and stops at the first match, via the existing ISqlTemplate.query(sql, maxRowsToFetch, ...) overload. Same for the delivered-batch check. Both SQL keys renamed from count* to select* to match. - The free in-memory row-count check now runs before that query rather than after, so the query is skipped entirely in the case it would answer. - recoverStuckExtractRequests ran from queueWork every 10 seconds, but its own staleness threshold means a request cannot qualify until it has been untouched for 5 minutes. Twenty-nine of every thirty scans could not have a new answer, and each walked every completed request for the node plus a correlated probe into the outgoing batch table. It now skips until the threshold has elapsed. Placement: FileSyncExtractorService extends DataExtractorService and does not override queueWork, so the recovery was also running on the file-sync instance, where it would have scanned and restarted ordinary data extract requests and then resolved their staging through the file-sync getStagedResource override. It now returns 0 there, matching how updateExtractRequestsForThreading is already handled in that class for the same reason. Also: added the missing @OverRide; extracted the two nine-argument log statements that repeated the same sentence into describeStuckRequest; extracted the load-range plus child-requests plus restart idiom, which resetExtractRequest already performed, into a shared restartExtractRequest(request) that keeps the parent guard rather than relying on the SQL filter to imply it. Corrected the javadoc: it claimed the detection is "exact rather than heuristic", but the zero-row clause is a heuristic. The batch-status half is exact; the heuristic half is now labelled as one, with the case it misjudges named. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
|
| // changeBatchStatus does not persist in this mode, so the batch's own row would still read RQ. | ||
| return false; | ||
| } | ||
| if (request.getEndBatchId() > request.getStartBatchId() && currentBatch.getExtractRowCount() == 0 && request.getRows() > 0) { |
There was a problem hiding this comment.
Unfortunately this condition is hard to read... Making it hard to support.
There are plenty of variables inplay:
- Clustered servers overtaking each other's load requests (without prior crash).
- Own multi-threaded processing streams racing to re-do potentially crashed reqiuest.
I wonder if a more productive way to move forward is a demo with this issue discussed in a medium-sized gathering?..
Also, voluminous comments are a "code smell". It alerts reviewer that logic is so complex/convoluted/unrefined that code alone is not no longer self-documenting...
Pavel_JM (pavel-jm)
left a comment
There was a problem hiding this comment.
Let's schedule a code review/debate meeting to settle on the best idea to solve this?
| public static final String INITIAL_LOAD_CONCAT_CSV_IN_SQL_ENABLED = "initial.load.concat.csv.in.sql.enabled"; | ||
| public static final String INITIAL_LOAD_USE_COLUMN_TEMPLATES_ENABLED = "initial.load.use.column.templates.enabled"; | ||
| public static final String INITIAL_LOAD_EXTRACT_THREAD_COUNT_PER_SERVER = "initial.load.extract.thread.per.server.count"; | ||
| public static final String INITIAL_LOAD_EXTRACT_REQUEST_RECOVERY_ENABLED = "initial.load.extract.request.recovery.enabled"; |
There was a problem hiding this comment.
Not sure why this is new parameter is needed?
I was hoping the issue is fixed without user needing to analyse it and set parameters?


Fixes SYM-7915.
The problem
An initial load whose extract is interrupted by a JVM restart comes back permanently stuck.
sym_extract_requestreadsOKwithextracted_rows=0while its batches are stillRQ. Every extraction selector filters onNEso nothing re-extracts it,extractBatchrefuses to deliver anRQbatch, nothing reconciles the two, and nothing surfaces it.The only symptom in the product is a pair of INFO log lines. The console shows an ACTIVE pipeline making no progress, indistinguishable from a slow load. At the reporting site it ran three days, was never recovered, and the load had to be discarded.
Root cause
extractOutgoingBatchmarked the entire request — all of its batches —OKfrom a single batch'sextract_row_countandextract_millis, with no check that anything was extracted and no check that the rest of the range had finished. A batch that skipped extraction because it was already extracted contributes a zero row count and a near-zero duration, which is exactly the row observed.Three layers
isExtractRequestCompletegates the status write. When incomplete, statistics accumulate through a new incremental statement instead, so progress stays visible without claiming completion.recoverStuckExtractRequestsreturns such requests toNE, called fromqueueWork, whichInitialLoadExtractorJobalready drives. That covers startup for free. A startup-only check would not have helped the reporting site, whose node ran three days in this state.restartExtractRequestnow also zeroesextracted_rows/extracted_millis, which it previously left behind.Why the detection has no false positives
MultiBatchStagingWriter.close()advances every remaining batch in the range, so a finished extract leaves none atRQ. A request atOKwith anRQbatch in its range is an impossible state, not a healthy in-flight one. That is what makes both the guard and the reconciler safe against a running extract.The constraint that shapes the recovery
restartExtractRequestflips the whole range back toRQthroughupdateOutgoingBatchStatusSql, which carries no status predicate — so it re-sends batches that already landed. Requests whose range contains delivered batches are therefore not restarted automatically; they are reported at ERROR every pass with the recovery choices and requireforce. The product cannot know whether the target tolerates a re-apply, and the field evidence (500,000 rows committed with nosym_incoming_batchrow) shows the target's own record can be untrustworthy.Review notes
sym_outgoing_batch.DataExtractorServiceis the only implementer of the interface andFileSyncExtractorServiceinherits it; there is no PRO implementer, so the interface addition breaks nothing.FileSyncExtractorServicereturns 0 from the recovery, matching howupdateExtractRequestsForThreadingis already handled there — otherwise it would scan and restart ordinary data extract requests and resolve their staging through the file-sync override.count(*): the answers are booleans, and a count visits the whole batch range, so across a load split into N batches the cost would grow with N².queueWorkruns every 10s but a request cannot qualify for 5 minutes, so 29 of every 30 scans could not have a new answer.781 tests pass in
:symmetric-core, 0 failures.Not covered here
The end-to-end kill-and-recover path needs a real database — it is on the ticket as manual QA.
Found while reading and deliberately not folded in:
sym_extract_requestrows are inserted asLSand flippedLS→NEbyDataService, and nothing recovers anLSrequest either, so a kill during load setup strands a load the same way. The reconciler is the natural home, but it is a separate defect and should be its own ticket.🤖 Generated with Claude Code