From d4531904fd6585a381b3eec3507359d02b7d9f3d Mon Sep 17 00:00:00 2001 From: DarkIsDude Date: Wed, 15 Oct 2025 14:51:43 +0200 Subject: [PATCH 1/4] =?UTF-8?q?=E2=9C=85=20update=20test=20to=20manage=20r?= =?UTF-8?q?ace=20condition?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Issue: CLDSRV-765 --- .../aws-node-sdk/test/object/copyPart.js | 60 +++++++++++++------ 1 file changed, 43 insertions(+), 17 deletions(-) diff --git a/tests/functional/aws-node-sdk/test/object/copyPart.js b/tests/functional/aws-node-sdk/test/object/copyPart.js index f87780b706..ab607e7959 100644 --- a/tests/functional/aws-node-sdk/test/object/copyPart.js +++ b/tests/functional/aws-node-sdk/test/object/copyPart.js @@ -609,18 +609,43 @@ describe('Object Part Copy', () => { process.stdout.write( 'Overwriting first part in MPU test and completing MPU at the same time', ); + + const completeMPU = () => s3 + .completeMultipartUpload({ + Bucket: destBucketName, + Key: randomDestObjName, + UploadId: uploadId, + MultipartUpload: { + Parts: [{ ETag: etag, PartNumber: 1 }], + }, + }).promise(); + const [completeRes, uploadRes] = await Promise.all([ - s3 - .completeMultipartUpload({ - Bucket: destBucketName, - Key: randomDestObjName, - UploadId: uploadId, - MultipartUpload: { - Parts: [{ ETag: etag, PartNumber: 1 }], - }, - }) - .promise() - .catch(err => { + completeMPU() + .catch(async err => { + // The completeMPU delete part in a 2 steps + // (first mark it as deletion with `delete: true` in Mongo, then delete it). + // At the same time, the uploadPartCopy update the same data in Mongo. + // In that case, the completeMPU fail with an InternalError (DeleteConflict in the logs) + const raceConditionOccurred = err && err.code === 'InternalError'; + + if (raceConditionOccurred) { + process.stdout.write('Retrying the complete MPU'); + + try { + await completeMPU(); + } catch (e) { + if (e.code === 'NoSuchUpload') { + process.stdout.write('Race condition done'); + return Promise.resolve(null); + } + + throw e; + } + + throw new Error('Expected error on the retry of complete MPU'); + } + throw err; }), s3 @@ -648,12 +673,13 @@ describe('Object Part Copy', () => { assert(uploadRes.LastModified); } - assert.strictEqual(completeRes.Bucket, destBucketName); - assert.strictEqual(completeRes.Key, randomDestObjName); - assert.strictEqual(completeRes.ETag, finalObjETag); - process.stdout.write( - 'Getting object put by MPU with ' + 'overwrite part', - ); + if (completeRes !== null) { + assert.strictEqual(completeRes.Bucket, destBucketName); + assert.strictEqual(completeRes.Key, randomDestObjName); + assert.strictEqual(completeRes.ETag, finalObjETag); + } + + process.stdout.write('Getting object put by MPU with overwrite part'); const resGet = await s3 .getObject({ Bucket: destBucketName, From fe2225c3d42c249e8b0f48812b3aa5f09c1c4c93 Mon Sep 17 00:00:00 2001 From: DarkIsDude Date: Tue, 21 Oct 2025 17:19:43 +0200 Subject: [PATCH 2/4] =?UTF-8?q?=E2=99=BB=EF=B8=8F=20use=20a=20custom=20err?= =?UTF-8?q?or=20description=20to=20detect=20the=20conflict=20and=20the=20s?= =?UTF-8?q?pecific=20race=20condition?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Issue: CLDSRV-765 --- lib/api/completeMultipartUpload.js | 25 ++- lib/services.js | 24 ++- .../aws-node-sdk/test/object/copyPart.js | 152 +++++++++--------- 3 files changed, 118 insertions(+), 83 deletions(-) diff --git a/lib/api/completeMultipartUpload.js b/lib/api/completeMultipartUpload.js index 88197d1bfc..5962221a0b 100644 --- a/lib/api/completeMultipartUpload.js +++ b/lib/api/completeMultipartUpload.js @@ -1,6 +1,6 @@ const async = require('async'); const { parseString } = require('xml2js'); -const { errors, versioning, s3middleware, storage } = require('arsenal'); +const { errors, errorInstances, versioning, s3middleware, storage } = require('arsenal'); const convertToXml = s3middleware.convertToXml; const { pushMetric } = require('../utapi/utilities'); @@ -535,28 +535,49 @@ function completeMultipartUpload(authInfo, request, log, callback) { }, function deletePartsMetadata(mpuBucket, keysToDelete, aggregateETag, extraPartLocations, destinationBucket, generatedVersionId, droppedMPUSize, next) { + log.warn('Deleting MPU parts metadata', { method: 'completeMultipartUpload' }); services.batchDeleteObjectMetadata(mpuBucket.getName(), keysToDelete, log, err => { if (err) { + log.warn( + 'error deleting MPU parts metadata', + { error: err, method: 'deletePartsMetadata' }, + ); + console.info({ errorCustom: JSON.stringify(err) }); // Handle specific error cases according to retry strategy if (err.is?.DeleteConflict) { + log.warn( + 'conflict deleting MPU parts metadata, will retry', + { method: 'deletePartsMetadata' }, + ); // DeleteConflict should trigger automatic retry // Convert to InternalError to make it retryable - return next(errors.InternalError, extraPartLocations, + const customErr = errorInstances.InternalError.customizeDescription( + 'conflict deleting MPU parts metadata' + ); + + return next(customErr, extraPartLocations, destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize); } // For NoSuchKey and other errors, return them as-is // NoSuchKey is non-retryable, InternalError and others are retryable + log.warn( + 'error deleting MPU parts metadata, returning error', + { method: 'deletePartsMetadata' }, + ); return next(err, extraPartLocations, destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize); } + + log.warn('Successfully deleted MPU parts metadata', { method: 'deletePartsMetadta' }); return next(null, extraPartLocations, destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize); }); }, function batchDeleteExtraParts(extraPartLocations, destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize, next) { + log.warn('deleting extra parts if any', { method: 'batchDeleteExtraParts' }); if (extraPartLocations && extraPartLocations.length > 0) { return data.batchDelete(extraPartLocations, request.method, null, log, err => { if (err) { diff --git a/lib/services.js b/lib/services.js index ce7c89358b..4356574bf7 100644 --- a/lib/services.js +++ b/lib/services.js @@ -984,8 +984,28 @@ const services = { // all at once in production implementation assert.strictEqual(typeof mpuBucketName, 'string'); async.eachLimit(keysToDelete, 5, (key, callback) => { - metadata.deleteObjectMD(mpuBucketName, key, { overheadField: constants.overheadField }, log, callback); - }, err => cb(err)); + metadata.deleteObjectMD(mpuBucketName, key, { overheadField: constants.overheadField }, log, err => { + if (err) { + console.info({ errorInBatch: err }); + log.error('error deleting part metadata in batch', { + error: err, + method: 'services.batchDeleteObjectMetadata', + key, + }); + } + return callback(err); + }); + }, err => { + if (err) { + console.info({ finalErrorInBatch: err }); + log.error('error in batch (final) deleting part metadata', { + error: err, + method: 'services.batchDeleteObjectMetadata', + }); + } + + return cb(err); + }); }, }; diff --git a/tests/functional/aws-node-sdk/test/object/copyPart.js b/tests/functional/aws-node-sdk/test/object/copyPart.js index ab607e7959..0b5c423503 100644 --- a/tests/functional/aws-node-sdk/test/object/copyPart.js +++ b/tests/functional/aws-node-sdk/test/object/copyPart.js @@ -580,113 +580,107 @@ describe('Object Part Copy', () => { }); }); - it('should not corrupt object if overwriting an existing part by copying a part ' + + it.only('should not corrupt object if overwriting an existing part by copying a part ' + 'while the MPU is being completed', async () => { - const finalObjETag = '"db77ebbae9e9f5a244a26b86193ad818-1"'; - process.stdout.write('Putting first part in MPU test"'); - const randomDestObjName = `copycatobject${Math.floor(Math.random() * 100000)}`; + const finalObjETag = '"db77ebbae9e9f5a244a26b86193ad818-1"'; + process.stdout.write('Putting first part in MPU test"'); + const randomDestObjName = `copycatobject${Math.floor(Math.random() * 100000)}`; - const initiateRes = await s3 - .createMultipartUpload({ + const initiateRes = await s3 + .createMultipartUpload({ Bucket: destBucketName, Key: randomDestObjName, - }) - .promise(); - const uploadId = initiateRes.UploadId; + }) + .promise(); + const uploadId = initiateRes.UploadId; - const res = await s3 - .uploadPartCopy({ + const res = await s3 + .uploadPartCopy({ Bucket: destBucketName, Key: randomDestObjName, CopySource: `${sourceBucketName}/${sourceObjName}`, PartNumber: 1, UploadId: uploadId, - }) - .promise(); - assert.strictEqual(res.ETag, etag); - assert(res.LastModified); + }) + .promise(); + assert.strictEqual(res.ETag, etag); + assert(res.LastModified); - process.stdout.write( - 'Overwriting first part in MPU test and completing MPU at the same time', - ); + process.stdout.write( + 'Overwriting first part in MPU test and completing MPU at the same time', + ); - const completeMPU = () => s3 - .completeMultipartUpload({ - Bucket: destBucketName, - Key: randomDestObjName, - UploadId: uploadId, - MultipartUpload: { - Parts: [{ ETag: etag, PartNumber: 1 }], - }, - }).promise(); - - const [completeRes, uploadRes] = await Promise.all([ - completeMPU() + const [completeRes, uploadRes] = await Promise.all([ + s3 + .completeMultipartUpload({ + Bucket: destBucketName, + Key: randomDestObjName, + UploadId: uploadId, + MultipartUpload: { + Parts: [{ ETag: etag, PartNumber: 1 }], + }, + }).promise() .catch(async err => { - // The completeMPU delete part in a 2 steps - // (first mark it as deletion with `delete: true` in Mongo, then delete it). - // At the same time, the uploadPartCopy update the same data in Mongo. - // In that case, the completeMPU fail with an InternalError (DeleteConflict in the logs) - const raceConditionOccurred = err && err.code === 'InternalError'; - - if (raceConditionOccurred) { - process.stdout.write('Retrying the complete MPU'); - - try { - await completeMPU(); - } catch (e) { - if (e.code === 'NoSuchUpload') { - process.stdout.write('Race condition done'); + // The completeMPU delete part in a 2 steps + // (first mark it as deletion with `delete: true` in Mongo, then delete it). + // At the same time, the uploadPartCopy update the same data in Mongo. + // In that case, the completeMPU fail with an InternalError (DeleteConflict in the logs) + const raceConditionOccurred = err?.code === 'InternalError' + && err?.message === 'conflict deleting MPU parts metadata'; + + console.info({ + raceConditionOccurred, + err, + message: err?.message, + description: err.description, + code: err?.code, + }); + + if (raceConditionOccurred) { return Promise.resolve(null); - } - - throw e; } - - throw new Error('Expected error on the retry of complete MPU'); - } - throw err; + throw err; }), - s3 + s3 .uploadPartCopy({ - Bucket: destBucketName, - Key: randomDestObjName, - CopySource: `${sourceBucketName}/${sourceObjName}`, - PartNumber: 1, - UploadId: uploadId, + Bucket: destBucketName, + Key: randomDestObjName, + CopySource: `${sourceBucketName}/${sourceObjName}`, + PartNumber: 1, + UploadId: uploadId, }) .promise() .catch(err => { - const completeMPUFinishedEarlier = - err && err.code === 'NoSuchKey'; - if (completeMPUFinishedEarlier) { - return Promise.resolve(null); - } + const completeMPUFinishedEarlier = err && err.code === 'NoSuchKey'; + if (completeMPUFinishedEarlier) { + return Promise.resolve(null); + } - throw err; + throw err; }), - ]); + ], + ); - if (uploadRes !== null) { - assert.strictEqual(uploadRes.ETag, etag); - assert(uploadRes.LastModified); - } + if (uploadRes !== null) { + assert.strictEqual(uploadRes.ETag, etag); + assert(uploadRes.LastModified); + } - if (completeRes !== null) { - assert.strictEqual(completeRes.Bucket, destBucketName); - assert.strictEqual(completeRes.Key, randomDestObjName); - assert.strictEqual(completeRes.ETag, finalObjETag); - } + if (completeRes !== null) { + assert.strictEqual(completeRes.Bucket, destBucketName); + assert.strictEqual(completeRes.Key, randomDestObjName); + assert.strictEqual(completeRes.ETag, finalObjETag); + } - process.stdout.write('Getting object put by MPU with overwrite part'); - const resGet = await s3 - .getObject({ + process.stdout.write('Getting object put by MPU with overwrite part'); + const resGet = await s3 + .getObject({ Bucket: destBucketName, Key: randomDestObjName, - }) - .promise(); - assert.strictEqual(resGet.ETag, finalObjETag); + }) + .promise(); + assert.strictEqual(resGet.ETag, finalObjETag); }); }); From f89c54acd663d245fe346c42dfc27dc0038b6962 Mon Sep 17 00:00:00 2001 From: DarkIsDude Date: Wed, 22 Oct 2025 10:54:02 +0200 Subject: [PATCH 3/4] =?UTF-8?q?=E2=AC=86=EF=B8=8F=20upgrade=20arsenal=20to?= =?UTF-8?q?=20use=20the=20DeleteConflict=20error?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Issue: CLDSRV-765 --- package.json | 2 +- yarn.lock | 6 +++--- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/package.json b/package.json index 5a8d35efbb..f5bfc9602e 100644 --- a/package.json +++ b/package.json @@ -21,7 +21,7 @@ "dependencies": { "@azure/storage-blob": "^12.28.0", "@hapi/joi": "^17.1.1", - "arsenal": "git+https://github.com/scality/Arsenal#8.2.35", + "arsenal": "git+https://github.com/scality/Arsenal#8.2.37", "async": "2.6.4", "aws-sdk": "^2.1692.0", "bucketclient": "scality/bucketclient#8.2.7", diff --git a/yarn.lock b/yarn.lock index 9edededc50..e1b4a475a6 100644 --- a/yarn.lock +++ b/yarn.lock @@ -1451,9 +1451,9 @@ arraybuffer.prototype.slice@^1.0.4: optionalDependencies: ioctl "^2.0.2" -"arsenal@git+https://github.com/scality/Arsenal#8.2.35": - version "8.2.35" - resolved "git+https://github.com/scality/Arsenal#51640ec484e521925e2d3a8b7ce5912f61590b8d" +"arsenal@git+https://github.com/scality/Arsenal#8.2.37": + version "8.2.37" + resolved "git+https://github.com/scality/Arsenal#a000b510e641b819f86d91371f638f1cbc57144f" dependencies: "@azure/identity" "^4.13.0" "@azure/storage-blob" "^12.28.0" From 8b4f5bd09f33f82fefb8f6544bbb08a2f2d7bf3a Mon Sep 17 00:00:00 2001 From: DarkIsDude Date: Wed, 22 Oct 2025 11:34:09 +0200 Subject: [PATCH 4/4] =?UTF-8?q?=F0=9F=94=87=20remove=20logs=20used=20to=20?= =?UTF-8?q?debug?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Issue: CLDSRV-765 --- lib/api/completeMultipartUpload.js | 17 ------------- lib/services.js | 24 ++----------------- .../aws-node-sdk/test/object/copyPart.js | 14 +---------- 3 files changed, 3 insertions(+), 52 deletions(-) diff --git a/lib/api/completeMultipartUpload.js b/lib/api/completeMultipartUpload.js index 5962221a0b..7f076fef7a 100644 --- a/lib/api/completeMultipartUpload.js +++ b/lib/api/completeMultipartUpload.js @@ -535,21 +535,10 @@ function completeMultipartUpload(authInfo, request, log, callback) { }, function deletePartsMetadata(mpuBucket, keysToDelete, aggregateETag, extraPartLocations, destinationBucket, generatedVersionId, droppedMPUSize, next) { - log.warn('Deleting MPU parts metadata', { method: 'completeMultipartUpload' }); services.batchDeleteObjectMetadata(mpuBucket.getName(), keysToDelete, log, err => { if (err) { - log.warn( - 'error deleting MPU parts metadata', - { error: err, method: 'deletePartsMetadata' }, - ); - console.info({ errorCustom: JSON.stringify(err) }); - // Handle specific error cases according to retry strategy if (err.is?.DeleteConflict) { - log.warn( - 'conflict deleting MPU parts metadata, will retry', - { method: 'deletePartsMetadata' }, - ); // DeleteConflict should trigger automatic retry // Convert to InternalError to make it retryable const customErr = errorInstances.InternalError.customizeDescription( @@ -562,22 +551,16 @@ function completeMultipartUpload(authInfo, request, log, callback) { // For NoSuchKey and other errors, return them as-is // NoSuchKey is non-retryable, InternalError and others are retryable - log.warn( - 'error deleting MPU parts metadata, returning error', - { method: 'deletePartsMetadata' }, - ); return next(err, extraPartLocations, destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize); } - log.warn('Successfully deleted MPU parts metadata', { method: 'deletePartsMetadta' }); return next(null, extraPartLocations, destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize); }); }, function batchDeleteExtraParts(extraPartLocations, destinationBucket, aggregateETag, generatedVersionId, droppedMPUSize, next) { - log.warn('deleting extra parts if any', { method: 'batchDeleteExtraParts' }); if (extraPartLocations && extraPartLocations.length > 0) { return data.batchDelete(extraPartLocations, request.method, null, log, err => { if (err) { diff --git a/lib/services.js b/lib/services.js index 4356574bf7..cbf8740170 100644 --- a/lib/services.js +++ b/lib/services.js @@ -984,28 +984,8 @@ const services = { // all at once in production implementation assert.strictEqual(typeof mpuBucketName, 'string'); async.eachLimit(keysToDelete, 5, (key, callback) => { - metadata.deleteObjectMD(mpuBucketName, key, { overheadField: constants.overheadField }, log, err => { - if (err) { - console.info({ errorInBatch: err }); - log.error('error deleting part metadata in batch', { - error: err, - method: 'services.batchDeleteObjectMetadata', - key, - }); - } - return callback(err); - }); - }, err => { - if (err) { - console.info({ finalErrorInBatch: err }); - log.error('error in batch (final) deleting part metadata', { - error: err, - method: 'services.batchDeleteObjectMetadata', - }); - } - - return cb(err); - }); + metadata.deleteObjectMD(mpuBucketName, key, { overheadField: constants.overheadField }, log, callback); + }, cb); }, }; diff --git a/tests/functional/aws-node-sdk/test/object/copyPart.js b/tests/functional/aws-node-sdk/test/object/copyPart.js index 0b5c423503..87f8f6b0c9 100644 --- a/tests/functional/aws-node-sdk/test/object/copyPart.js +++ b/tests/functional/aws-node-sdk/test/object/copyPart.js @@ -580,7 +580,7 @@ describe('Object Part Copy', () => { }); }); - it.only('should not corrupt object if overwriting an existing part by copying a part ' + + it('should not corrupt object if overwriting an existing part by copying a part ' + 'while the MPU is being completed', async () => { const finalObjETag = '"db77ebbae9e9f5a244a26b86193ad818-1"'; process.stdout.write('Putting first part in MPU test"'); @@ -621,21 +621,9 @@ describe('Object Part Copy', () => { }, }).promise() .catch(async err => { - // The completeMPU delete part in a 2 steps - // (first mark it as deletion with `delete: true` in Mongo, then delete it). - // At the same time, the uploadPartCopy update the same data in Mongo. - // In that case, the completeMPU fail with an InternalError (DeleteConflict in the logs) const raceConditionOccurred = err?.code === 'InternalError' && err?.message === 'conflict deleting MPU parts metadata'; - console.info({ - raceConditionOccurred, - err, - message: err?.message, - description: err.description, - code: err?.code, - }); - if (raceConditionOccurred) { return Promise.resolve(null); }