Skip to content

Commit 2faa037

Browse files
DarkIsDudeDarkIsDude
committed
♻️ use a custom error description to detect the conflict and the specific race condition
Issue: CLDSRV-765
1 parent 938e9c0 commit 2faa037

File tree

3 files changed

+118
-83
lines changed

3 files changed

+118
-83
lines changed

‎lib/api/completeMultipartUpload.js‎

Lines changed: 23 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
const async = require('async');
22
const { parseString } = require('xml2js');
3-
const { errors, versioning, s3middleware, storage } = require('arsenal');
3+
const { errors, errorInstances, versioning, s3middleware, storage } = require('arsenal');
44

55
const convertToXml = s3middleware.convertToXml;
66
const { pushMetric } = require('../utapi/utilities');
@@ -535,28 +535,49 @@ function completeMultipartUpload(authInfo, request, log, callback) {
535535
},
536536
function deletePartsMetadata(mpuBucket, keysToDelete, aggregateETag,
537537
extraPartLocations, destinationBucket, generatedVersionId, droppedMPUSize, next) {
538+
log.warn('Deleting MPU parts metadata', { method: 'completeMultipartUpload' });
538539
services.batchDeleteObjectMetadata(mpuBucket.getName(),
539540
keysToDelete, log, err => {
540541
if (err) {
542+
log.warn(
543+
'error deleting MPU parts metadata',
544+
{ error: err, method: 'deletePartsMetadata' },
545+
);
546+
console.info({ errorCustom: JSON.stringify(err) });
541547
// Handle specific error cases according to retry strategy
542548
if (err.is?.DeleteConflict) {
549+
log.warn(
550+
'conflict deleting MPU parts metadata, will retry',
551+
{ method: 'deletePartsMetadata' },
552+
);
543553
// DeleteConflict should trigger automatic retry
544554
// Convert to InternalError to make it retryable
545-
return next(errors.InternalError, extraPartLocations,
555+
const customErr = errorInstances.InternalError.customizeDescription(
556+
'conflict deleting MPU parts metadata'
557+
);
558+
559+
return next(customErr, extraPartLocations,
546560
destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize);
547561
}
548562

549563
// For NoSuchKey and other errors, return them as-is
550564
// NoSuchKey is non-retryable, InternalError and others are retryable
565+
log.warn(
566+
'error deleting MPU parts metadata, returning error',
567+
{ method: 'deletePartsMetadata' },
568+
);
551569
return next(err, extraPartLocations,
552570
destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize);
553571
}
572+
573+
log.warn('Successfully deleted MPU parts metadata', { method: 'deletePartsMetadta' });
554574
return next(null, extraPartLocations,
555575
destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize);
556576
});
557577
},
558578
function batchDeleteExtraParts(extraPartLocations, destinationBucket,
559579
aggregateETag, generatedVersionId, droppedMPUSize, next) {
580+
log.warn('deleting extra parts if any', { method: 'batchDeleteExtraParts' });
560581
if (extraPartLocations && extraPartLocations.length > 0) {
561582
return data.batchDelete(extraPartLocations, request.method, null, log, err => {
562583
if (err) {

‎lib/services.js‎

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -984,8 +984,28 @@ const services = {
984984
// all at once in production implementation
985985
assert.strictEqual(typeof mpuBucketName, 'string');
986986
async.eachLimit(keysToDelete, 5, (key, callback) => {
987-
metadata.deleteObjectMD(mpuBucketName, key, { overheadField: constants.overheadField }, log, callback);
988-
}, err => cb(err));
987+
metadata.deleteObjectMD(mpuBucketName, key, { overheadField: constants.overheadField }, log, err => {
988+
if (err) {
989+
console.info({ errorInBatch: err });
990+
log.error('error deleting part metadata in batch', {
991+
error: err,
992+
method: 'services.batchDeleteObjectMetadata',
993+
key,
994+
});
995+
}
996+
return callback(err);
997+
});
998+
}, err => {
999+
if (err) {
1000+
console.info({ finalErrorInBatch: err });
1001+
log.error('error in batch (final) deleting part metadata', {
1002+
error: err,
1003+
method: 'services.batchDeleteObjectMetadata',
1004+
});
1005+
}
1006+
1007+
return cb(err);
1008+
});
9891009
},
9901010
};
9911011

‎tests/functional/aws-node-sdk/test/object/copyPart.js‎

Lines changed: 73 additions & 79 deletions
Original file line numberDiff line numberDiff line change
@@ -580,113 +580,107 @@ describe('Object Part Copy', () => {
580580
});
581581
});
582582

583-
it('should not corrupt object if overwriting an existing part by copying a part ' +
583+
it.only('should not corrupt object if overwriting an existing part by copying a part ' +
584584
'while the MPU is being completed', async () => {
585-
const finalObjETag = '"db77ebbae9e9f5a244a26b86193ad818-1"';
586-
process.stdout.write('Putting first part in MPU test"');
587-
const randomDestObjName = `copycatobject${Math.floor(Math.random() * 100000)}`;
585+
const finalObjETag = '"db77ebbae9e9f5a244a26b86193ad818-1"';
586+
process.stdout.write('Putting first part in MPU test"');
587+
const randomDestObjName = `copycatobject${Math.floor(Math.random() * 100000)}`;
588588

589-
const initiateRes = await s3
590-
.createMultipartUpload({
589+
const initiateRes = await s3
590+
.createMultipartUpload({
591591
Bucket: destBucketName,
592592
Key: randomDestObjName,
593-
})
594-
.promise();
595-
const uploadId = initiateRes.UploadId;
593+
})
594+
.promise();
595+
const uploadId = initiateRes.UploadId;
596596

597-
const res = await s3
598-
.uploadPartCopy({
597+
const res = await s3
598+
.uploadPartCopy({
599599
Bucket: destBucketName,
600600
Key: randomDestObjName,
601601
CopySource: `${sourceBucketName}/${sourceObjName}`,
602602
PartNumber: 1,
603603
UploadId: uploadId,
604-
})
605-
.promise();
606-
assert.strictEqual(res.ETag, etag);
607-
assert(res.LastModified);
604+
})
605+
.promise();
606+
assert.strictEqual(res.ETag, etag);
607+
assert(res.LastModified);
608608

609-
process.stdout.write(
610-
'Overwriting first part in MPU test and completing MPU at the same time',
611-
);
609+
process.stdout.write(
610+
'Overwriting first part in MPU test and completing MPU at the same time',
611+
);
612612

613-
const completeMPU = () => s3
614-
.completeMultipartUpload({
615-
Bucket: destBucketName,
616-
Key: randomDestObjName,
617-
UploadId: uploadId,
618-
MultipartUpload: {
619-
Parts: [{ ETag: etag, PartNumber: 1 }],
620-
},
621-
}).promise();
622-
623-
const [completeRes, uploadRes] = await Promise.all([
624-
completeMPU()
613+
const [completeRes, uploadRes] = await Promise.all([
614+
s3
615+
.completeMultipartUpload({
616+
Bucket: destBucketName,
617+
Key: randomDestObjName,
618+
UploadId: uploadId,
619+
MultipartUpload: {
620+
Parts: [{ ETag: etag, PartNumber: 1 }],
621+
},
622+
}).promise()
625623
.catch(async err => {
626-
// The completeMPU delete part in a 2 steps
627-
// (first mark it as deletion with `delete: true` in Mongo, then delete it).
628-
// At the same time, the uploadPartCopy update the same data in Mongo.
629-
// In that case, the completeMPU fail with an InternalError (DeleteConflict in the logs)
630-
const raceConditionOccurred = err && err.code === 'InternalError';
631-
632-
if (raceConditionOccurred) {
633-
process.stdout.write('Retrying the complete MPU');
634-
635-
try {
636-
await completeMPU();
637-
} catch (e) {
638-
if (e.code === 'NoSuchUpload') {
639-
process.stdout.write('Race condition done');
624+
// The completeMPU delete part in a 2 steps
625+
// (first mark it as deletion with `delete: true` in Mongo, then delete it).
626+
// At the same time, the uploadPartCopy update the same data in Mongo.
627+
// In that case, the completeMPU fail with an InternalError (DeleteConflict in the logs)
628+
const raceConditionOccurred = err?.code === 'InternalError'
629+
&& err?.message === 'conflict deleting MPU parts metadata';
630+
631+
console.info({
632+
raceConditionOccurred,
633+
err,
634+
message: err?.message,
635+
description: err.description,
636+
code: err?.code,
637+
});
638+
639+
if (raceConditionOccurred) {
640640
return Promise.resolve(null);
641-
}
642-
643-
throw e;
644641
}
645-
646-
throw new Error('Expected error on the retry of complete MPU');
647-
}
648642

649-
throw err;
643+
throw err;
650644
}),
651-
s3
645+
s3
652646
.uploadPartCopy({
653-
Bucket: destBucketName,
654-
Key: randomDestObjName,
655-
CopySource: `${sourceBucketName}/${sourceObjName}`,
656-
PartNumber: 1,
657-
UploadId: uploadId,
647+
Bucket: destBucketName,
648+
Key: randomDestObjName,
649+
CopySource: `${sourceBucketName}/${sourceObjName}`,
650+
PartNumber: 1,
651+
UploadId: uploadId,
658652
})
659653
.promise()
660654
.catch(err => {
661-
const completeMPUFinishedEarlier =
662-
err && err.code === 'NoSuchKey';
663-
if (completeMPUFinishedEarlier) {
664-
return Promise.resolve(null);
665-
}
655+
const completeMPUFinishedEarlier = err && err.code === 'NoSuchKey';
656+
if (completeMPUFinishedEarlier) {
657+
return Promise.resolve(null);
658+
}
666659

667-
throw err;
660+
throw err;
668661
}),
669-
]);
662+
],
663+
);
670664

671-
if (uploadRes !== null) {
672-
assert.strictEqual(uploadRes.ETag, etag);
673-
assert(uploadRes.LastModified);
674-
}
665+
if (uploadRes !== null) {
666+
assert.strictEqual(uploadRes.ETag, etag);
667+
assert(uploadRes.LastModified);
668+
}
675669

676-
if (completeRes !== null) {
677-
assert.strictEqual(completeRes.Bucket, destBucketName);
678-
assert.strictEqual(completeRes.Key, randomDestObjName);
679-
assert.strictEqual(completeRes.ETag, finalObjETag);
680-
}
670+
if (completeRes !== null) {
671+
assert.strictEqual(completeRes.Bucket, destBucketName);
672+
assert.strictEqual(completeRes.Key, randomDestObjName);
673+
assert.strictEqual(completeRes.ETag, finalObjETag);
674+
}
681675

682-
process.stdout.write('Getting object put by MPU with overwrite part');
683-
const resGet = await s3
684-
.getObject({
676+
process.stdout.write('Getting object put by MPU with overwrite part');
677+
const resGet = await s3
678+
.getObject({
685679
Bucket: destBucketName,
686680
Key: randomDestObjName,
687-
})
688-
.promise();
689-
assert.strictEqual(resGet.ETag, finalObjETag);
681+
})
682+
.promise();
683+
assert.strictEqual(resGet.ETag, finalObjETag);
690684
});
691685
});
692686

0 commit comments

Comments
 (0)