Skip to content
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,10 @@
{
"changes": [
{
"packageName": "@itwin/core-backend",
"comment": "",
"type": "none"
}
],
"packageName": "@itwin/core-backend"
}
60 changes: 48 additions & 12 deletions core/backend/src/CloudSqlite.ts
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ import { mkdirSync, unlinkSync } from "fs";
import { dirname, join } from "path";
import { NativeLibrary } from "@bentley/imodeljs-native";
import {
AccessToken, BeDuration, BriefcaseStatus, Constructor, GuidString, Logger, LogLevel, OpenMode, Optional, PickAsyncMethods, PickMethods, StopWatch,
AccessToken, BeDuration, BriefcaseStatus, Constructor, GuidString, ITwinError, Logger, LogLevel, OpenMode, Optional, PickAsyncMethods, PickMethods, StopWatch,
} from "@itwin/core-bentley";
import { CloudSqliteError, LocalDirName, LocalFileName } from "@itwin/core-common";
import { BlobContainer } from "./BlobContainerService";
Expand Down Expand Up @@ -693,6 +693,16 @@ export namespace CloudSqlite {
promise: Promise<boolean>;
}

/**
* Determine if error is a "transfer already completed" error.
* @param err Any thrown error
* @returns true if the error is a "transfer already completed" error, or false otherwise.
* @internal
*/
function isTransferAlreadyCompletedError(err: any): boolean {
return ITwinError.isError(err, "imodel-native", "BadArg") && err.message === "transfer already completed";
Comment thread
tcobbs-bentley marked this conversation as resolved.
}

/**
* Clean any unused deleted blocks from cloud storage. Unused deleted blocks can accumulate in cloud storage in a couple of ways:
* 1) When a database is updated, a subset of its blocks are replaced by new versions, sometimes leaving the originals unused.
Expand All @@ -710,13 +720,26 @@ export namespace CloudSqlite {
const onProgress = options?.onProgress;
if (onProgress) {
timer = setInterval(async () => { // set an interval timer to show progress every 250ms
const progress = cleanJob.getProgress();
total = progress.total;
const result = await onProgress(progress.loaded, progress.total);
if (result === 1)
cleanJob.stopAndSaveProgress();
else if (result !== 0)
cleanJob.cancelTransfer();
try {
const progress = cleanJob.getProgress();
total = progress.total;
const result = await onProgress(progress.loaded, progress.total);
if (result === 1)
cleanJob.stopAndSaveProgress();
else if (result !== 0)
cleanJob.cancelTransfer();
} catch (err: any) {
if (timer) {
clearInterval(timer);
timer = undefined;
}
// A race condition exists where cleanJob has completed but the timer has not yet been cleared, or it
// completes while we are waiting on the onProgress callback. If this happens, we will get an error from any
// function call made to cleanJob after the job is done. In that case, just ignore the error.
if (isTransferAlreadyCompletedError(err))
return;
throw err;
}
}, 250);
}
await cleanJob.promise;
Expand Down Expand Up @@ -745,10 +768,23 @@ export namespace CloudSqlite {
const onProgress = props.onProgress;
if (onProgress) {
timer = setInterval(async () => { // set an interval timer to show progress every 250ms
const progress = transfer.getProgress();
total = progress.total;
if (onProgress(progress.loaded, progress.total))
transfer.cancelTransfer();
try {
const progress = transfer.getProgress();
total = progress.total;
if (onProgress(progress.loaded, progress.total))
transfer.cancelTransfer();
} catch (err: any) {
if (timer) {
clearInterval(timer);
timer = undefined;
}
// A race condition exists where transfer has completed but the timer has not yet been cleared. If this
// happens, we will get an error from any function call made to transfer after the job is done. In that
// case, just ignore the error.
if (isTransferAlreadyCompletedError(err))
return;
throw err;
}
}, 250);
}
await transfer.promise;
Expand Down
87 changes: 86 additions & 1 deletion full-stack-tests/backend/src/integration/CloudSqlite.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -565,7 +565,7 @@ describe("CloudSqlite", () => {
newCache2.destroy();
});

it("should be able to interrupt cleanDeletedBlocks operation", async () => {
const prepareDbForCleaningBlocks = async () => {
const cache = azSqlite.makeCache("clean-blocks-cache");
const container = testContainers[0];

Expand Down Expand Up @@ -600,6 +600,11 @@ describe("CloudSqlite", () => {

expect(container.garbageBlocks).to.be.greaterThan(0);
const garbageBlocksPrev = container.garbageBlocks;
return { container, garbageBlocksPrev };
Comment thread
tcobbs-bentley marked this conversation as resolved.
}
Comment thread
github-code-quality[bot] marked this conversation as resolved.
Fixed

it("should be able to interrupt cleanDeletedBlocks operation", async () => {
const { container, garbageBlocksPrev } = await prepareDbForCleaningBlocks();

// cleanDeletedBlocks defaults to an nSeconds of 3600, so we expect to keep our garbage blocks, because they are less than 3600 seconds old.
await CloudSqlite.cleanDeletedBlocks(container, {});
Expand Down Expand Up @@ -653,6 +658,86 @@ describe("CloudSqlite", () => {
container.disconnect({ detach: true });
});

it("slow cleanDeletedBlocks onProgress should not cause race condition", async () => {
const { container } = await prepareDbForCleaningBlocks();

let progressCalled = false;
let progressWaited = false;
const onProgress = async () => {
if (!progressCalled) {
progressCalled = true;
await BeDuration.wait(2000); // simulate a long onProgress callback that takes 2000ms to complete.
// await new Promise((resolve) => clock.setTimeout(resolve, 2000)); // simulate a long onProgress callback that takes 2000ms to complete.
progressWaited = true; // We have to wait for onProgress to finish before we can be sure that cleanDeletedBlocks
Comment thread
tcobbs-bentley marked this conversation as resolved.
// didn't throw an error after our return.
return 2; // return a number greater than 1 to abort the cleanDeletedBlocks operation.
}
return 0; // return 0 to not abort the cleanDeletedBlocks operation.
}
Comment thread
github-code-quality[bot] marked this conversation as resolved.
Fixed

// In the past, cleanDeletedBlocks would occasionally throw an error inside a setInterval handler. This is because a
// race condition could cause the handler to still be called after cleanDeletedBlocks had already resolved and
// cleaned up its resources, including the container it was operating on. If the handler was called after
// cleanDeletedBlocks had resolved, or if onProgress took a long time and returned non-zero, then it would try to
// access the container that was already cleaned up, which would cause an error to be thrown. This race condition
// could be forced by having a slow onProgress handler return non-zero. This test makes sure that even if onProgress
// is slow, we don't have unhandled rejections or uncaught exceptions. The race condition was fixed, but we don't
// want to accidentally regress it, so this test will stay.
//
// Note: we would like to add a similar test for transferDb, but the progress callback for transferDb is not async,
// so there is no way to simulate a long onProgress callback that would cause the race condition.
const unhandledRejections: Array<any> = [];
const rejectionHandler = (reason: any) => {
unhandledRejections.push(reason);
};
process.on("unhandledRejection", rejectionHandler);

// Capture uncaught exceptions
const uncaughtExceptions: Error[] = [];
const exceptionHandler = (error: Error) => {
uncaughtExceptions.push(error);
};
process.on("uncaughtException", exceptionHandler);

try {
// Faking the interval setup in cleanDeletedBlocks.
const clock = sinon.useFakeTimers({ toFake: ["setInterval"], shouldAdvanceTime: true, advanceTimeDelta: 1 });
let resolved = false;
CloudSqlite.cleanDeletedBlocks(container, { nSeconds: 0, findOrphanedBlocks: true, onProgress }).then(() => {
resolved = true;
}).catch(() => {
resolved = true;
});

while (!resolved || !progressWaited) {
await clock.tickAsync(250);
await new Promise((resolve) => clock.setTimeout(resolve, 1));
}
// Give a bit more time for any async errors to surface
await clock.tickAsync(100);
await new Promise((resolve) => setImmediate(resolve));
clock.reset();
clock.restore();

// Check for unhandled errors
if (unhandledRejections.length > 0) {
throw new Error(`Unhandled rejection detected: ${unhandledRejections[0]}`);
}
if (uncaughtExceptions.length > 0) {
throw new Error(`Uncaught exception detected: ${uncaughtExceptions[0].message}`);
}

container.checkForChanges();
expect(container.garbageBlocks).to.be.equal(0); // we should have successfully cleaned our garbage blocks, because of slow onProgress.

container.releaseWriteLock();
container.disconnect({ detach: true });
} finally {
process.off("unhandledRejection", rejectionHandler);
Comment thread
tcobbs-bentley marked this conversation as resolved.
process.off("uncaughtException", exceptionHandler);
}
});

/** make sure that the auto-refresh for container tokens happens every hour */
it("Auto refresh container tokens", async () => {
const contain1 = testContainers[0];
Expand Down
Loading