CompleteMultipartUpload sometimes fail after resending same part

[evgeniiz321]

test_multipart_resend

Create upload, send part 1, resend part 1, complete upload with ETag from the resend. Time to time fails with

One or more of the specified parts could not be found.  The part may not have been uploaded, or the specified entity tag may not match the part's entity tag

Full log for the test:

2023-11-08T03:48:58.827Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "8064fad9-2c99-49a9-8162-43611bc34730", "method": "CreateBucket", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "object": "", "description": "OK"}
2023-11-08T03:48:58.873Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "fd1a1430-d7f9-42c9-8f5f-01f366774c71", "method": "CreateMultipartUpload", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:48:59.620Z	debug	layer/multipart_upload.go:233	upload part	{"reqId": "a9be0f9d-b677-493c-97d8-834164eab0e4", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "cid": "GqXGsoWCsNHoWgDsfzrcaWmxnzFsSXKLNJZbyW4yG84E", "multipart upload": "7acaa3ad-cf65-45e4-b88d-c0dfdc722785", "part number": 1, "object": "mymultipart", "oid": "6MfTwP3XXduT7xfDvxyfFDaMKtdLub4D5m49Aiiitvqq"}
2023-11-08T03:48:59.773Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "a9be0f9d-b677-493c-97d8-834164eab0e4", "method": "UploadPart", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:49:00.448Z	debug	layer/multipart_upload.go:233	upload part	{"reqId": "6fc8178e-8a4d-4b66-abf2-810dbbd234c6", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "cid": "GqXGsoWCsNHoWgDsfzrcaWmxnzFsSXKLNJZbyW4yG84E", "multipart upload": "7acaa3ad-cf65-45e4-b88d-c0dfdc722785", "part number": 1, "object": "mymultipart", "oid": "5GnabGcdXUarRaT6xRgbUQ5LhPAYafY63nq5tVXXoztH"}
2023-11-08T03:49:00.559Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "6fc8178e-8a4d-4b66-abf2-810dbbd234c6", "method": "UploadPart", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:49:00.568Z	debug	layer/multipart_upload.go:629	part details	{"reqId": "c45d8727-30be-4e84-ae4d-6a4235a2a163", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "cid": "GqXGsoWCsNHoWgDsfzrcaWmxnzFsSXKLNJZbyW4yG84E", "object": "mymultipart", "upload id": "7acaa3ad-cf65-45e4-b88d-c0dfdc722785", "part numbers": [1, 1], "oids": ["5GnabGcdXUarRaT6xRgbUQ5LhPAYafY63nq5tVXXoztH", "6MfTwP3XXduT7xfDvxyfFDaMKtdLub4D5m49Aiiitvqq"]}
2023-11-08T03:49:00.568Z	error	handler/util.go:29	call method	{"status": 400, "request_id": "c45d8727-30be-4e84-ae4d-6a4235a2a163", "method": "CompleteMultipartUpload", "bucket": "yournamehere-dhlj7gbinpo5t4l1-1", "object": "mymultipart", "description": "could not complete multipart upload", "error": "InvalidPart: 400 => One or more of the specified parts could not be found.  The part may not have been uploaded, or the specified entity tag may not match the part's entity tag.", "uploadID": "7acaa3ad-cf65-45e4-b88d-c0dfdc722785", "Key": "mymultipart"}

And here is a log after the same test but when it passed:

2023-11-08T03:50:02.475Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "f99c3489-dc8c-459d-86cd-4a85d7004638", "method": "CreateMultipartUpload", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:50:02.852Z	debug	layer/multipart_upload.go:233	upload part	{"reqId": "fdf2c6f4-5216-4b68-a480-2d47015ce096", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "cid": "61PB1CGm2j4ZMKnvNHZQCo7rivNUdSqMAXruMgjk5nBo", "multipart upload": "90b06856-97a5-46f8-bd13-bc2f23c875d3", "part number": 1, "object": "mymultipart", "oid": "EPDXaEYcPHMR9uizL158tFhEZAkWQbPSLkagUfAHtbeQ"}
2023-11-08T03:50:02.905Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "fdf2c6f4-5216-4b68-a480-2d47015ce096", "method": "UploadPart", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:50:03.529Z	debug	layer/multipart_upload.go:233	upload part	{"reqId": "a8c1a2ea-3778-4c9b-a218-8fb2ba91102a", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "cid": "61PB1CGm2j4ZMKnvNHZQCo7rivNUdSqMAXruMgjk5nBo", "multipart upload": "90b06856-97a5-46f8-bd13-bc2f23c875d3", "part number": 1, "object": "mymultipart", "oid": "EgPcAciG6ejnDoY2qmCoS2KRSYBYRRuHmbuyLhTw56M9"}
2023-11-08T03:50:03.547Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "a8c1a2ea-3778-4c9b-a218-8fb2ba91102a", "method": "UploadPart", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:50:03.558Z	debug	layer/multipart_upload.go:629	part details	{"reqId": "39348a5a-32a9-4277-b2e5-71ab90df1b43", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "cid": "61PB1CGm2j4ZMKnvNHZQCo7rivNUdSqMAXruMgjk5nBo", "object": "mymultipart", "upload id": "90b06856-97a5-46f8-bd13-bc2f23c875d3", "part numbers": [1, 1], "oids": ["EPDXaEYcPHMR9uizL158tFhEZAkWQbPSLkagUfAHtbeQ", "EgPcAciG6ejnDoY2qmCoS2KRSYBYRRuHmbuyLhTw56M9"]}
2023-11-08T03:50:03.989Z	debug	layer/object.go:258	put object	{"reqId": "39348a5a-32a9-4277-b2e5-71ab90df1b43", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "cid": "61PB1CGm2j4ZMKnvNHZQCo7rivNUdSqMAXruMgjk5nBo", "object": "mymultipart", "oid": "GqaAXC6rLojgZPvQBppA9raAXknXZ1rsZPHxSEN3AAHP"}
2023-11-08T03:50:05.581Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "39348a5a-32a9-4277-b2e5-71ab90df1b43", "method": "CompleteMultipartUpload", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:50:05.609Z	debug	layer/layer.go:480	get object	{"reqId": "9065c9d2-43c9-4a9b-a08b-36612f7d6f5a", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "cid": "61PB1CGm2j4ZMKnvNHZQCo7rivNUdSqMAXruMgjk5nBo", "object": "mymultipart", "oid": "GqaAXC6rLojgZPvQBppA9raAXknXZ1rsZPHxSEN3AAHP"}
2023-11-08T03:50:05.612Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "9065c9d2-43c9-4a9b-a08b-36612f7d6f5a", "method": "HeadObject", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "object": "mymultipart", "description": "OK"}
2023-11-08T03:50:05.621Z	debug	layer/layer.go:480	get object	{"reqId": "579d5df0-b9d5-4d06-945d-059a5c9e72c7", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "cid": "61PB1CGm2j4ZMKnvNHZQCo7rivNUdSqMAXruMgjk5nBo", "object": "mymultipart", "oid": "GqaAXC6rLojgZPvQBppA9raAXknXZ1rsZPHxSEN3AAHP"}
2023-11-08T03:50:05.628Z	info	api/router.go:165	call method	{"status": 200, "host": "s3.neofs.devenv:8080", "request_id": "579d5df0-b9d5-4d06-945d-059a5c9e72c7", "method": "GetObject", "bucket": "yournamehere-mqqhsz3jh9rg62x4-1", "object": "mymultipart", "description": "OK"}

[smallhive]

The problem exists and it is in the same part. As a result, we have in our "part list" two parts with the same ID, but with different ETags. Unfortunately, they may have a similar creation date. This date is taken from the client and this time is a part of the request signature routine, thus we can't change it or replace it on our side.

As a possible solution, we can extend partInfo inside the tree service and put serverCreatedTime, which will be different from request to request. In this case, we can sort all parts and last uploaded rewrite all previous and ETag will be actual.
But there is one more issue with the complete list from the client and it's ETag. Required more deep investigations