Skip to content
Open
Show file tree
Hide file tree
Changes from all 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
181 changes: 181 additions & 0 deletions src/__tests__/services/LibraryServicePathMutations.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -328,6 +328,187 @@ describe('LibraryService — path-mutating flows (move / rename / folder_in_out)

expect(moveFileMock).not.toHaveBeenCalled();
});

it('pins source_path to the pre-move key when the relocation fails, so the row still names the object that exists', async () => {
const trx = getTestTransaction();
const user = await createTestUser(trx);
const book = await createTestLibraryItem(trx, {
user_id: user.id_user,
key: 'Legacy.m4b',
source_path: null,
});
await createTestLibraryItem(trx, {
user_id: user.id_user,
key: '0_FINISHED',
type: 0,
});
moveFileMock.mockImplementation(async () => false);
// The copy failed, but the object is still sitting at its old key.
fileExistsMock.mockImplementation(async () => true);

await service.moveLibraryObject(user as any, {
origin: 'Legacy.m4b',
destination: '0_FINISHED',
});

const bookAfter = await trx('library_items')
.where({ id_library_item: book.id_library_item })
.first();
// The move still commits — it is a display-path change — but the row now
// points at the object's real, un-moved location instead of at nothing.
expect(bookAfter.key).toBe('0_FINISHED/Legacy.m4b');
expect(bookAfter.source_path).toBe('Legacy.m4b');
});

it('does not strip the source_path of items relocated earlier in the same batch', async () => {
const trx = getTestTransaction();
const user = await createTestUser(trx);
await createTestLibraryItem(trx, {
user_id: user.id_user,
key: 'Series',
type: 0,
});
const moved = await createTestLibraryItem(trx, {
user_id: user.id_user,
key: 'Series/a.m4b',
source_path: null,
});
const stranded = await createTestLibraryItem(trx, {
user_id: user.id_user,
key: 'Series/b.m4b',
source_path: null,
});
await createTestLibraryItem(trx, {
user_id: user.id_user,
key: '0_FINISHED',
type: 0,
});
// Only the second child fails to relocate.
moveFileMock.mockImplementation(async (params: unknown) => {
const { sourceKey } = params as { sourceKey: string };
return !sourceKey.endsWith('b.m4b');
});
fileExistsMock.mockImplementation(async () => true);

await service.moveLibraryObject(user as any, {
origin: 'Series',
destination: '0_FINISHED',
});

const movedAfter = await trx('library_items')
.where({ id_library_item: moved.id_library_item })
.first();
const strandedAfter = await trx('library_items')
.where({ id_library_item: stranded.id_library_item })
.first();
// The one that did relocate keeps the timestamped key naming its new
// object (ROOT_FOLDER is not set in CI, so assert the shape, not the
// prefix)...
expect(movedAfter.key).toBe('0_FINISHED/Series/a.m4b');
expect(movedAfter.source_path).toMatch(/_a\.m4b$/);
expect(movedAfter.source_path).not.toBe('Series/a.m4b');
// ...while the one that did not is pinned to where its bytes still are.
expect(strandedAfter.key).toBe('0_FINISHED/Series/b.m4b');
expect(strandedAfter.source_path).toBe('Series/b.m4b');
});

it('leaves source_path null when the relocation failed because nothing was at the old key', async () => {
const trx = getTestTransaction();
const user = await createTestUser(trx);
const book = await createTestLibraryItem(trx, {
user_id: user.id_user,
key: 'Phantom.m4b',
source_path: null,
});
await createTestLibraryItem(trx, {
user_id: user.id_user,
key: '0_FINISHED',
type: 0,
});
moveFileMock.mockImplementation(async () => false);
fileExistsMock.mockImplementation(async () => false);

await service.moveLibraryObject(user as any, {
origin: 'Phantom.m4b',
destination: '0_FINISHED',
});

const bookAfter = await trx('library_items')
.where({ id_library_item: book.id_library_item })
.first();
// There are no bytes at either key, so pinning would only record a path
// that holds nothing — and freeze the item, since a set source_path
// skips the relocation on every later move.
expect(bookAfter.key).toBe('0_FINISHED/Phantom.m4b');
expect(bookAfter.source_path).toBeNull();
});

it('pins to the new key when the delete landed but its response was lost', async () => {
const trx = getTestTransaction();
const user = await createTestUser(trx);
const book = await createTestLibraryItem(trx, {
user_id: user.id_user,
key: 'Lost.m4b',
source_path: null,
});
await createTestLibraryItem(trx, {
user_id: user.id_user,
key: '0_FINISHED',
type: 0,
});
// moveFile is copy-then-delete: the copy landed and the delete actually
// ran on S3, but the SDK call threw, so the move reports failure while
// the bytes are already at the target and gone from the source.
moveFileMock.mockImplementation(async () => false);
fileExistsMock.mockImplementation(async (params: unknown) => {
const { key } = params as { key: string };
return key !== 'test-prefix/Lost.m4b';
});

await service.moveLibraryObject(user as any, {
origin: 'Lost.m4b',
destination: '0_FINISHED',
});

const bookAfter = await trx('library_items')
.where({ id_library_item: book.id_library_item })
.first();
// The move really did happen, so pin to the target, not the dead source.
expect(bookAfter.key).toBe('0_FINISHED/Lost.m4b');
expect(bookAfter.source_path).not.toBeNull();
expect(bookAfter.source_path).not.toBe('Lost.m4b');
expect(bookAfter.source_path).toMatch(/_Lost\.m4b$/);
});

it('still pins to the old key when the existence probe itself fails', async () => {
const trx = getTestTransaction();
const user = await createTestUser(trx);
const book = await createTestLibraryItem(trx, {
user_id: user.id_user,
key: 'Probe.m4b',
source_path: null,
});
await createTestLibraryItem(trx, {
user_id: user.id_user,
key: '0_FINISHED',
type: 0,
});
moveFileMock.mockImplementation(async () => false);
// null = could not determine. Must not be read as "absent", or the row
// would be left naming nothing — the bug this whole path guards against.
fileExistsMock.mockImplementation(async () => null);

await service.moveLibraryObject(user as any, {
origin: 'Probe.m4b',
destination: '0_FINISHED',
});

const bookAfter = await trx('library_items')
.where({ id_library_item: book.id_library_item })
.first();
expect(bookAfter.key).toBe('0_FINISHED/Probe.m4b');
expect(bookAfter.source_path).toBe('Probe.m4b');
});
});

describe('renameLibraryObject — /rename body { relativePath, newName, uuid }', () => {
Expand Down
70 changes: 70 additions & 0 deletions src/__tests__/services/S3ServiceFileExists.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
import { describe, it, expect, beforeEach, jest } from '@jest/globals';
import { S3Service } from '../../services/S3Service';
import { mockLoggerService } from '../setup';

/**
* fileExists is tri-state, and LibraryService.processMovedFiles depends on the
* distinction: only a definitive `false` from BOTH the source and target probe
* lets it conclude a moved item's bytes are nowhere and leave source_path null.
* A probe that merely could not determine the answer must come back as null, or
* that path records "nothing exists" on an object it was simply unable to read.
*/
describe('S3Service.fileExists — tri-state', () => {
let service: S3Service;
let headObjectMock: jest.Mock;

beforeEach(() => {
service = new S3Service();
headObjectMock = jest.fn();
(service as any).client = { headObject: headObjectMock };
(service as any)._logger = mockLoggerService;
mockLoggerService.log.mockClear();
});

it('returns true when the object is there', async () => {
headObjectMock.mockImplementation(async () => ({
$metadata: { httpStatusCode: 200 },
}));
await expect(service.fileExists('prefix/root/a.m4b')).resolves.toBe(true);
});

it('returns false for a 404 — definitively absent', async () => {
headObjectMock.mockImplementation(async () => {
throw Object.assign(new Error('Not Found'), {
$metadata: { httpStatusCode: 404 },
});
});
await expect(service.fileExists('prefix/root/a.m4b')).resolves.toBe(false);
});

it('returns null for a 403 — denied is not the same as absent', async () => {
headObjectMock.mockImplementation(async () => {
throw Object.assign(new Error('Forbidden'), {
$metadata: { httpStatusCode: 403 },
});
});
await expect(service.fileExists('prefix/root/a.m4b')).resolves.toBeNull();
});

it('returns null for any other failure', async () => {
headObjectMock.mockImplementation(async () => {
throw Object.assign(new Error('boom'), {
$metadata: { httpStatusCode: 500 },
});
});
await expect(service.fileExists('prefix/root/a.m4b')).resolves.toBeNull();
});

it('does not log the storage prefix, which can be the account email', async () => {
headObjectMock.mockImplementation(async () => {
throw Object.assign(new Error('Forbidden'), {
$metadata: { httpStatusCode: 403 },
});
});
await service.fileExists('someone@example.com/root/a.m4b');

const logged = JSON.stringify(mockLoggerService.log.mock.calls);
expect(logged).not.toContain('someone@example.com');
expect(logged).toContain('root/a.m4b');
});
});
37 changes: 37 additions & 0 deletions src/__tests__/utils/stripStoragePrefix.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@
import { describe, it, expect } from '@jest/globals';
import { stripStoragePrefix } from '../../utils';

/**
* stripStoragePrefix is what keeps a legacy account's email address out of
* CloudWatch: the per-user storage prefix is `users.external_id`, or that
* address for accounts predating it (see StoragePrefixService). These cases
* pin the edges so a later simplification cannot quietly reintroduce the leak.
*/
describe('stripStoragePrefix', () => {
it('drops the prefix segment and keeps the rest of the key', () => {
expect(stripStoragePrefix('someone@example.com/root/1_a.mp3')).toBe(
'root/1_a.mp3',
);
});

it('keeps every segment after the first', () => {
expect(
stripStoragePrefix('someone@example.com/TV/Bluey/S01/[E01] Bike.mp3'),
).toBe('TV/Bluey/S01/[E01] Bike.mp3');
});

it('returns empty for a bare prefix, rather than echoing the address', () => {
expect(stripStoragePrefix('someone@example.com')).toBe('');
});

it('returns empty for missing or empty input', () => {
expect(stripStoragePrefix(undefined)).toBe('');
expect(stripStoragePrefix('')).toBe('');
});

it('handles an external_id prefix the same way', () => {
expect(
stripStoragePrefix('001172.22b2d822a90b45bf8c4d250c3dda4d6a.1714/root/x.m4b'),
).toBe('root/x.m4b');
});
});
85 changes: 74 additions & 11 deletions src/services/LibraryService.ts
Original file line number Diff line number Diff line change
Expand Up @@ -1253,11 +1253,7 @@ export class LibraryService {
!fileMoved.source_path &&
parseInt(fileMoved.type) === parseInt(LibraryItemType.BOOK)
) {
const suffix =
parseInt(fileMoved.type) === parseInt(LibraryItemType.BOOK)
? ''
: '/';
const sourceKey = `${storagePrefix}/${fileMoved.old_key}${suffix}`;
const sourceKey = `${storagePrefix}/${fileMoved.old_key}`;
const original_filename = `${
process.env.ROOT_FOLDER
}/${moment().format('YYYYMMDDHHmmss')}_${
Expand All @@ -1268,16 +1264,83 @@ export class LibraryService {
sourceKey,
targetKey,
});
if (isMoved) {
await this._libraryDB.updateBySourcePath(
// Either way the row must end up naming the object that actually
// exists. A legacy item (source_path IS NULL) is read back at
// `${prefix}/${key}`, so once the key rewrite commits, an object
// still sitting at old_key is unreachable — the row would point at
// nothing while the bytes are orphaned under the pre-move path.
//
// Throwing to roll the rewrite back is not an option: the items
// relocated earlier in this batch are already at their new keys,
// and the rollback would strip the source_path that names them,
// orphaning those instead. So on failure we record where the file
// really is. The move itself still succeeds — it is a display-path
// change — and the item stays playable from its legacy key.
// Where the object is, as best we can establish it.
let pinnedSourcePath = original_filename;

if (!isMoved) {
// A failed move does not locate the bytes on its own. moveFile
// is copy-then-delete, so the failure may be a copy that never
// landed (bytes at old_key) or a delete that landed on S3 but
// lost its response (bytes at the target, source already gone).
// fileExists also reports 403 as false, so a false is "could not
// find it", not "it is not there". Probe before concluding.
const sourceStillThere = await this._storage.fileExists({
Comment thread
GianniCarlo marked this conversation as resolved.

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔵 INFO — These probes run inside the caller's transaction (trx is threaded straight through to updateBySourcePath), so each failed item now adds one or two synchronous headObject round trips while holding the pooled connection and the row locks taken by the key rewrite. On a large folder move where S3 is the thing that is unhealthy — precisely when this path fires — the probe latency is also the worst, and the failure mode escalates from "one broken row" to "a sync transaction pinned open across many S3 timeouts".

The S3 client has no explicit timeout configured here, so consider a short requestHandler timeout on the client used for probes, or capping the number of items probed per batch and pinning the rest to old_key (the common-case answer) without a probe.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Flagging this one for a maintainer rather than picking an option.

Worth noting the framing: S3 calls already ran inside this transaction before the PR — moveFile is a copy plus a delete per item, called from the same place with the same trx. The probes add one or two HEADs on the failure path only, so this is roughly a 1.5-2x increase in round trips on an already-pathological path, not a new class of exposure. That is a reason to weigh the options rather than to rush one in.

The suggestions differ materially:

  1. A requestHandler timeout on the S3 client is global — the same client serves getObjectStream, so a short timeout risks breaking large-file streaming. It would need a separate client for probes.
  2. Capping probes per batch and pinning the rest to old_key unprobed trades away the correctness this PR just established: the unprobed items go back to being pinned blind, which is exactly what rounds 2 and 3 were about.
  3. Accepting it leaves a pre-existing characteristic in place.

Different trade-offs on different axes, so leaving it for the maintainers to choose as a follow-up.

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reported again on the newest commit, worded differently — the current wording is:

Still open from the previous push: these probes run inside the caller's transaction (trx is threaded straight to updateBySourcePath), so each failed item adds one or two synchronous headObject round trips while the pooled connection and the row locks from the key rewrite are held. This path fires precisely when S3 is unhealthy, which is also when probe latency is worst, and the S3 client is built with no requestHandler timeout (new S3({ region }) in S3Service), so the default SDK retry/timeout budget applies.

Concrete options: configure a short requestHandler connect/socket timeout on the client used for probes, or cap the number of probed items per batch and pin the remainder to old_key (the common-case answer) without probing.

key: sourceKey,
});
const targetLanded =
sourceStillThere === false
? await this._storage.fileExists({ key: targetKey })
: null;

// Anything short of a definitive "source is gone" means the
// object is, or is presumed, still at the old key — the common
// case, and the safe default when the probe itself failed
// (fileExists returns null then).
if (sourceStillThere !== false) {
pinnedSourcePath = fileMoved.old_key;
}

// Nothing found at either key. Pinning would record a path that
// holds nothing and freeze the row: the guard above skips items
// that already have a source_path, so no later move would retry
// the relocation. Leave it null instead — still broken, but
// still detectable and still retryable.
const foundNothing =
Comment thread
GianniCarlo marked this conversation as resolved.
sourceStillThere === false && targetLanded !== true;

this._logger.log(
{
user_id: user.id_user,
key: fileMoved.key,
source_path: original_filename,
origin: 'LibraryService.processMovedFiles',
message: 'Storage relocation failed',
data: {
id_user: user.id_user,
oldKey: fileMoved.old_key,
newKey: fileMoved.key,
sourceStillThere,
targetLanded,
// The decision itself, not just its inputs. A remediation
// sweep can then separate a confirmed phantom (both
// probes 404) from one where the target probe only came
// back indeterminate.
foundNothing,
targetIndeterminate: targetLanded === null,
pinnedSourcePath: foundNothing ? null : pinnedSourcePath,
},
},
trx,
'error',
);
if (foundNothing) continue;

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔵 INFO — The give-up branch leaves the row in the exact state the PR describes as invisible-by-default: source_path NULL, request still 200, and recordSyncOperation derives outcome from res.statusCode (src/api/middlewares/recordSyncOperation.ts:147), so sync_operations will again record applied / 200. The only trace is the CloudWatch line above, which is subject to log retention — the same gap that made the original 146-item case discoverable only by diffing DB keys against a bucket listing.

Since the durable audit table already exists, consider making processMovedFiles return the degraded item count and having the controller stash it on res.locals for the audit middleware to persist (or record the unresolved item ids directly). That would let the planned remediation sweep query Postgres instead of depending on log retention.

}
await this._libraryDB.updateBySourcePath(
{
user_id: user.id_user,
key: fileMoved.key,
source_path: pinnedSourcePath,
},
trx,
);
}
}
}),
Expand Down
Loading
Loading