Repository navigation
[#174] Enforce syncFileRetentionCount, reuse an existing CSV snapshot of the same mtime and fail sync() on a token without a snapshot - #200
Conversation
… mtime and advance the token to it
…ileRetentionCount
…t and take one in getLatestSyncToken
… releases the read lock A sync queued on the write lock could take it between the failing sync's read-lock release and its write-locked delete, reuse the failing sync's snapshot and hand out its token, which the delete then left without a snapshot. The read lock keeps other syncs out just as the write lock did.
maximthomas
added
bug
A sync keeps only the snapshot it reads, for a token and for its own baseline. Kills an early return for a count below 1 and a scrub that spares only a reused origin.
… in its help text The scrub runs when a sync starts and never deletes the snapshot that sync reads, so "number of sync history files to retain" undercounts what stays on disk.
…e absolute CSV file A CSV file named without a directory has no parent file, so listing its snapshots failed with a NullPointerException in every sync and in getLatestSyncToken. The listing now uses the absolute directory, and so does the one helper that names a snapshot: a relative origin would never equal its listed file, and the scrub would delete the snapshot the sync is about to read.
…snapshot only if it holds the same bytes Every snapshot is named after the mtime read before its copy, so one a sync in another JVM took may also hold a write made after that mtime was read. Adopting it as the token hid that write from this consumer for good. The end of a sync now adopts an existing snapshot only when it holds the same bytes as the sync's copy; otherwise the token stays, and the next sync reports these changes again. A snapshot that cannot be read is logged and not adopted.
…c for a delete with no lock held The fair lock let the queued sync take the write lock first, which pins a delete taken back under the write lock, but a delete with no lock held raced with the queued sync and survived most runs. The test now swaps in a lock whose read-lock release waits until the queued sync has taken its baseline, so both orders fail on every run.
vharseko
left a comment
vharseko
left a comment
There was a problem hiding this comment.
1. The scrub orders snapshots by the mtime in their names, so when the CSV file's mtime moves back, it deletes the snapshot that another consumer just got as its token (CSVFileConnector.java:1079-1091)
scrubSyncFiles deletes the lowest keys first. These are the oldest snapshots only while the CSV file's mtime keeps moving forward. Suppose the file is replaced by one with an older mtime (cp -p, rsync -t, a restore from backup, touch -d). The sync that reports that change then names its snapshot with the smallest key, and the next sync of another consumer deletes that snapshot first. That consumer made no new snapshot. The trade-offs list covers tokens lost to "more than syncFileRetentionCount newer snapshots" made by other consumers, and here there are none.
Repro: a same-package TestNG case at a2acb12, with retention 2 and two consumers.
- Given:
data.csv.1300000000000holdsk(consumer B's token).data.csv.1400000000000holdsk,d(consumer A's token). The live file holdsk, with its mtime set to1200000000000. - A syncs from
1400000000000and getsDELETE dand token1200000000000. The snapshots are now.1200…,.1300…,.1400…. - B syncs from
1300000000000and gets no deltas. Its scrub deletesdata.csv.1200000000000. - A syncs from
1200000000000and fails:ConnectorException: Snapshot …/data.csv.1200000000000 of sync token 1200000000000 does not exist, so the changes since that token cannot be reported; reset the sync token.
With the live mtime at 1500000000000 instead, the same steps pass, because the scrub stops at B's origin, the oldest snapshot. On master the scrub deletes nothing, so A's token survives in both cases.
A possible fix is to delete snapshots in the order they were taken and use the name only as the token. The snapshot file's own mtime gives that order: copyCsvFile copies without COPY_ATTRIBUTES, and Files.move keeps the copy's mtime, so it is the time of the copy. If that is out of scope, the case could go into the trade-offs instead.
2. Nit: the read lock is now released after the delete loop, outside a finally (:707-:713)
Before, rwLock.readLock().unlock() was the first statement of the finally. Now it comes after for (File copy : copies) deleteRewriteFile(copy). If that loop throws, the unlock is skipped. In practice that means an Error, or a SecurityException from File.delete(). Every later write and sync on that CSV file in this JVM then blocks on the write lock for good. A nested try { … } finally { rwLock.readLock().unlock(); } keeps the new order and still guarantees the unlock.
3. Nit: a snapshot deleted meanwhile is rejected without the WARN (:1374)
The length check runs before the try, and File.length() returns 0 for a missing file. The javadoc's own example, "one deleted meanwhile in another JVM", therefore returns false at the length check, and "Could not compare …" is never logged. The result is right; only the WARN that the description promises is missing. Comparing Files.size(...) inside the try would log it, because Files.size throws NoSuchFileException.
…st token in the order they were taken The scrub deleted the snapshots with the lowest mtime in their names first. Those are the oldest only while the CSV file's mtime moves forward. After a restore from a backup, cp -p or rsync -t, the sync that reports the change names its snapshot with the lowest mtime, and the next scrub of another consumer deleted it, so the next sync from that token failed. A snapshot is copied without the attributes of the CSV file and renamed into place, so its own mtime is the time of its copy. listSnapshots() now orders snapshots by that mtime, with a stable sort over the name order, so snapshots taken in one tick of a coarse clock keep the order of their names. getLatestSyncToken returns the token of the snapshot taken last, which the scrub keeps longest, instead of the newest name, which the scrub could now delete first.
… even if deleting its snapshots throws The read lock was released after the loop that deletes the snapshots of a failed sync, outside a finally block. An Error or a SecurityException from that loop left it held, and every later write and sync of that CSV file in this JVM then waited for the write lock for good. The release now runs in a finally block of its own, still after the loop, and the copy for the diff is deleted after it as before.
… byte comparison The length check ran before the try block, and File.length() returns 0 for a missing file, so a snapshot deleted meanwhile in another JVM was rejected without the "Could not compare" WARN. The sizes are now compared after both files are opened, where a missing snapshot throws NoSuchFileException and is logged.
|
Answering review 5614427012 (at a2acb12). New head: 2ada596. All three points held; the module runs 163 tests, 0 failures, and the PR body (Trade-offs, Test strength) is updated. 1. Scrub order when the CSV file's mtime moves back (ce1ca89) Your case, as
One case is left, and it is listed under Trade-offs. A snapshot reused by its name (the baseline of a sync without a token, or an existing snapshot adopted at the end) keeps the time of its first copy. That only matters when the mtime moves back to the mtime of an existing snapshot. 2. Read lock released outside a Fixed with the nested 3. No WARN for a snapshot deleted meanwhile (2ada596) The size check now runs inside the |
![github-advanced-security[bot]](https://avatars.githubusercontent.com/in/57789?s=60&v=4){kind=small}
| for (String name : names) { | ||
| final Matcher matcher = snapshotName.matcher(name); | ||
| if (matcher.matches()) { | ||
| byName.put(Long.valueOf(matcher.group(1)), new File(dataDir, name)); |
…y as its mtime on Windows too The scrub and getLatestSyncToken order snapshots by their own mtime, taken to be the time of their copy. Files.copy gives a copy that mtime on Linux and macOS only: on Windows it calls CopyFileEx, which keeps the last-write time of the CSV file, so the order fell back to the mtime in the names. Both Windows CI jobs failed syncKeepsTheTokenOfAnotherConsumerWhenTheCsvFileMtimeMovesBack: after the CSV file's mtime moved back, the scrub of another consumer deleted the snapshot just handed out as a token. Each copy for a snapshot now gets the current time as its mtime before it is renamed into place. A copy whose mtime cannot be set is logged as a WARN and used as it is, so a copy deleted meanwhile still fails the read that follows, as before.
3 participants
Fixes #174.
CSVFileConnector.sync()now deletes the snapshots beyondsyncFileRetentionCount, reuses an existing snapshot of the CSV file's current mtime instead of failing, advances the token to such a snapshot when it holds the bytes the sync read, matches snapshot names exactly, and fails on a token whose snapshot is gone instead of silently taking a new baseline.getLatestSyncTokentakes a snapshot when none exists, so the first sync from its token reports every change made after the call.<csv>.<13-digit mtime>are listed by one helper,listSnapshots(), withPattern.quote(name) + "\\.([0-9]{13})"andMatcher.matches(). The old pattern,"(" + name + ")(\\.[0-9]{13})$"withfind(), also matched the snapshots ofold_data.csvanddataXcsv, never matched those ofdata(1).csv, and threwPatternSyntaxExceptionfordata[1.csv. A directory that cannot be listed now fails withConnectorIOException"Unable to list the files of " instead of aNullPointerException. The listing uses the directory of the absolute CSV file, and one helper,snapshotFile(), names every snapshot from the absolute CSV file. So a CSV file named without a directory (csvFile=data.csv) no longer fails every sync andgetLatestSyncTokenwith aNullPointerException, and the scrub still recognises the snapshot the sync reads.scrubSyncFilesnow deletes files. At the start of every sync, under the write lock, it deletes the snapshots taken first untilsyncFileRetentionCountremain, but never the snapshot the sync is about to read. Snapshots are ordered by their own mtime, the time of their copy: each copy is given that mtime before it is renamed into place, becauseFiles.copygives it only on Linux and macOS, while on Windows itsCopyFileExkeeps the mtime of the CSV file. A copy whose mtime cannot be set is logged as WARN "Could not set the mtime of copy of to the time of the copy" and used as it is. Snapshots of one own mtime keep the order of their names. The mtime in a name gives that order only while the mtime of the CSV file never moves back: after a restore from a backup,cp -porrsync -t, the next scrub of another consumer deleted the snapshot just handed out as a token. A snapshot that cannot be deleted is logged as WARN "Could not delete " and kept. A count of 0 or below keeps only the snapshot the sync reads; a negative count used to throwArrayIndexOutOfBoundsException. ThesyncFileRetentionCounthelp text now says what is kept.takeSnapshot). If a snapshot of that mtime already exists, or another process takes it during the copy, it is reused as the baseline of a sync without a token. At the end of a sync, an existing snapshot of the copied mtime becomes the new token only if it holds the same bytes as the sync's copy. Every snapshot is named after the mtime read before its copy, so one taken in another JVM may also hold a later write that this sync has not reported. Then the token stays, and the next sync reports these changes again instead of never reporting that write. A snapshot that cannot be read, or that is gone by the time of the comparison, is logged as WARN "Could not compare with " and is not adopted. Before, the start copy failed withConnectorException"Unable to copy CSV file for sync operation", and the end always kept the old token, so a second consumer of the same changes got them again on every sync. A failed sync deletes only the snapshots it made, never one it reused.ConnectorException"Snapshot of sync token does not exist, so the changes since that token cannot be reported; reset the sync token". Before, it copied the live file as the baseline and so silently skipped every delete since the token.getLatestSyncTokenwithout any snapshot takes one of the CSV file and returns its mtime. Before, it returned the current time without a snapshot, so the first sync from that token copied the live file as its baseline and lost every change made in between. With snapshots, it returns the token of the one taken last, which the scrub keeps longest, instead of the token of the newest name.finallyblock of its own, so a delete that throws, such as with anError, does not leave it held.copies.clear()after a handled delta ([#171] Skip CSV snapshot rows without a uid and delete the snapshots a failed sync copied #183);syncFileRetentionCountis not validated.Trade-offs:
syncFileRetentionCount, under the write lock, so searches and writes on that CSV file in this JVM wait for it.getLatestSyncTokenreturned when no snapshot existed (the current time) that were never synced, and tokens whose snapshot a cleanup job deleted. Such cleanup jobs should be dropped: retention now does their work.syncFileRetentionCountsnapshots after it, or when the count is 0 or below and the file has several consumers. Its next sync then fails instead of silently skipping deletes.syncFileRetentionCount + 1snapshots stay on disk between syncs, or+ 2when the snapshot a sync read was taken before the kept ones.Files.movewithout options checks the target and then renames, so two JVMs can replace each other's snapshot of the same mtime. An existing snapshot of the copied mtime becomes the token only if its bytes match, so a later write in it is reported by the next sync instead of lost. In one JVM the bytes differ only when the file changed without its mtime changing, such as a write within the same mtime tick as an earlier sync's copy; that consumer then gets these changes again until the mtime moves.getLatestSyncTokentakes only the read lock, so it can return the snapshot of a sync that is failing at the same moment, which that sync then deletes. That needs a second consumer of the CSV file in this JVM; its next sync then fails and its token has to be reset.getLatestSyncTokenread the mtime of every snapshot of the CSV file to order them, and every snapshot copy sets its own.data.csv.1backup, and zero-padded names would break the stored tokens of such mtimes.<csv>.<digits>.tmpfiles left by a killed process are still not removed automatically.SyncOpTest#syncTestSuccessivenow syncs from the snapshot thatgetLatestSyncTokentakes, no longer through the re-copy for a missing snapshot.SyncOpDiffTest#syncOfAFileNamedWithoutADirectoryKeepsTheSnapshotItReadscreates a temporary CSV file in the surefire working directory, the module directory, and deletes it and its snapshots in afinallyblock. A killed test run leavescsv-sync-*.csv*files there.Test strength
All cases are in
SyncOpDiffTestunless named. "Red at " means that the case fails when this PR's tests run against theCSVFileConnectorof that commit: 95c8375 is master, and 2c0760a, b542f0d, a2acb12 and 2ada596 are earlier commits of this PR.CSVFileConnector.java:1073,:1077snapshot names are quoted and matched wholelatestSyncTokenIgnoresSnapshotsOfOtherFiles(old_data.csv,dataXcsv),latestSyncTokenFindsTheSnapshotsOfAFileWithRegexMetacharactersInItsName(data(1).csv,data[1.csv),syncOfAFileWhoseNameIsAnInvalidRegexReportsItsChangesfind():1071an unlistable directory fails withConnectorIOExceptionlatestSyncTokenOfAnUnlistableDirectoryFails(POSIX, non-root)NullPointerException):1054-:1055,:1068snapshot paths and the listing use the absolute CSV filesyncOfAFileNamedWithoutADirectoryKeepsTheSnapshotItReads(a temporary CSV file in the working directory, count 1)NullPointerException):739the snapshot taken last is the latest tokenSyncOpTest#syncTestSuccessive;latestSyncTokenIsThatOfTheSnapshotTakenLast(a snapshot of an older mtime taken after one of a newer mtime):1384an existing snapshot is reused, not copied againsecondSyncWithoutATokenOfAnUnchangedFileReusesItsSnapshotexists()check (4 copies instead of 3):493only a snapshot this call made goes intocopiesfailedSyncKeepsTheSnapshotItReused:1392,:1395a snapshot taken meanwhile by another process is kept, and the losing copy is deletedsnapshotTakenMeanwhileByAnotherProcessIsKept(overridescopyCsvFile()to write the snapshot):694-:695an existing snapshot at the end with the same bytes advances the tokenexistingSnapshotOfTheCopiedMtimeAdvancesTheToken,secondConsumerOfTheSameChangesGetsTheNewTokenToo:694,:1407-:1422an existing snapshot at the end with other bytes keeps the token and is not replacedexistingSnapshotOfTheCopiedMtimeWithOtherBytesKeepsTheToken(a row added; a change of the same length past the first 8 KiB):1425an existing snapshot that cannot be read is logged and keeps the tokenexistingSnapshotOfTheCopiedMtimeThatCannotBeReadKeepsTheToken(POSIX, non-root):689an existing snapshot at the end is not added tocopiesfailedSyncKeepsTheExistingSnapshotOfTheCopiedMtimecopies.add(syncOrigin)in the arm:1081-:1087the scrub deletes snapshots in the order they were taken, by their own mtimesyncKeepsTheTokenOfAnotherConsumerWhenTheCsvFileMtimeMovesBack(count 2, the CSV file's mtime set back below both tokens):522,:1387,:1369a snapshot copy gets the time of its copy as its mtime, also whereFiles.copykeeps the CSV file's mtime, asCopyFileExdoes on Windows[true]ofsyncKeepsTheTokenOfAnotherConsumerWhenTheCsvFileMtimeMovesBack(the copy for the next token) and oflatestSyncTokenIsThatOfABaselineTakenAfterTheCsvFileMtimeMovesBack(the baseline of a sync without a token, then the latest token);[true]overridescopyCsvFile()to keep the CSV file's mtimecopyCsvFile()instead at:522, and at:1387, each killed by its own case[true]of both); 95c8375 (both variants of the second case):1370-:1372a copy whose mtime cannot be set is logged and used as it iscopyDeletedBeforeItsMtimeIsSetLogsAWarning,copyDeletedBeforeTheIndexPassFailsSyncNamingTheCsvFile(the copy deleted at once):1087snapshots of one own mtime keep the order of their namessnapshotsTakenInOneTickAreScrubbedInTheOrderOfTheirNames(three snapshots of one own mtime, count 2):1098the configured count is usedsyncDeletesTheSnapshotsBeyondTheRetentionCount(count 2):1098,:1103a count of 0 or below keeps only the snapshot the sync readssyncFromATokenKeepsOnlyTheSnapshotItReads,syncWithoutATokenKeepsOnlyItsBaseline(counts 0 and -1)scrubSyncFiles(copies.isEmpty() ? syncOrigin : null), which spares only a reused originArrayIndexOutOfBoundsExceptionat -1):1103the snapshot the sync reads is sparedsyncKeepsTheSnapshotItReadsWhenItIsTheOldest(count 1):1097the scrub lists only this file's snapshotssyncKeepsTheSnapshotsOfOtherFiles(count 1)find():1104a snapshot that cannot be deleted is logged and keptsnapshotThatCannotBeScrubbedIsLogged(POSIX, non-root):481a token without a snapshot failssyncFromATokenWhoseSnapshotIsGoneFails:744getLatestSyncTokentakes a snapshot when there is nonelatestSyncTokenWithoutASnapshotTakesOne:713,:717a failed sync deletes its snapshots before it releases the read locksyncQueuedBehindAFailingSyncGetsATokenWithASnapshot(swaps a lock intofileNameToLockMapby reflection whose read-lock release waits until the queued sync has taken its baseline)finallyblock, the delete with no lock held still fails it:717the read lock is released even if a delete of a failed sync throwsfailedSyncReleasesTheReadLockWhenItsCleanupFails(POSIX, non-root: a read-only directory, andSystem.outswapped for a stream that throws, so the WARN "Could not delete" throws)finallyblock, as at a2acb12:745-:746a failed copy ingetLatestSyncTokenfails the callcatch (IOException e) { }survives, and the next sync would then fail with "Snapshot … does not exist":1408-:1410a snapshot gone by the time of the comparison is loggedexistingSnapshotOfTheCopiedMtimeDeletedMeanwhileIsLogged(a symbolic link to no file holds the snapshot name; skipped where links cannot be created)File.length()check before thetry, as at a2acb12, which returns 0 for a missing file:1410the size check before the byte comparison:1077the name must end after the 13 digitsmatches()→lookingAt()survives, and would list<csv>.<digits>.tmpfiles whose random part has 13 or more digitsmvn -pl OpenICF-csvfile-connector test: 167 run, 0 failures, 0 skipped (132 at 95c8375). Of the 79SyncOpDiffTestcases, 29 are red at 95c8375.