[#300] Update error log record in DeleteMultipleObjects #314

Merged

alexvanin merged 1 commits from mbiryukova/frostfs-s3-gw:feature/delete_multiple_objects_log_record into master

2024-02-29 14:24:33 +00:00

mbiryukova commented

2024-02-16 12:48:37 +00:00

Collaborator

Closes #300

mbiryukova self-assigned this 2024-02-16 12:48:37 +00:00

mbiryukova added 1 commit 2024-02-16 12:48:40 +00:00

/ DCO (pull_request) Successful in 1m28s Details

/ Builds (1.20) (pull_request) Successful in 2m11s Details

/ Builds (1.21) (pull_request) Successful in 1m32s Details

/ Vulncheck (pull_request) Successful in 2m23s Details

/ Lint (pull_request) Failing after 2m49s Details

/ Tests (1.20) (pull_request) Successful in 2m33s Details

/ Tests (1.21) (pull_request) Successful in 2m28s Details

fb6bf25b0d [#300 ] Update error log record in DeleteMultipleObjects

Signed-off-by: Marina Biryukova <m.biryukova@yadro.com>

mbiryukova requested review from storage-services-committers 2024-02-16 12:53:12 +00:00

mbiryukova requested review from storage-services-developers 2024-02-16 12:53:12 +00:00

dkirillov commented

2024-02-19 09:10:42 +00:00

Collaborator

Maybe we can revise logging of this handler taking into account the following points:

log error on single object here sequentially during removing (don't wait until all object be tried to delete, can be usefull when error is some timeout errors). But this can require distinguishing multiple deletion from single one in that method
don't log objects to remove at all / or log them always. Currently we log all objects only in some errors

cc @alexvanin

Maybe we can revise logging of this handler taking into account the following points: * log error on single object [here](https://git.frostfs.info/TrueCloudLab/frostfs-s3-gw/src/commit/bd8d2d00ba466fe76755d6da6b3c26d892643ba9/api/layer/layer.go#L765) sequentially during removing (don't wait until all object be tried to delete, can be usefull when error is some timeout errors). But this can require distinguishing multiple deletion from single one in that method * don't log objects to remove at all / or log them always. Currently we log all objects only in [some](https://git.frostfs.info/TrueCloudLab/frostfs-s3-gw/src/commit/bd8d2d00ba466fe76755d6da6b3c26d892643ba9/api/handler/delete.go#L263) [errors](https://git.frostfs.info/TrueCloudLab/frostfs-s3-gw/src/commit/bd8d2d00ba466fe76755d6da6b3c26d892643ba9/api/handler/delete.go#L270) cc @alexvanin

alexvanin approved these changes 2024-02-21 15:03:56 +00:00

alexvanin commented

2024-02-21 15:07:59 +00:00

Owner

log error on single object here sequentially during removing (don't wait until all object be tried to delete, can be usefull when error is some timeout errors). But this can require distinguishing multiple deletion from single one in that method

Can we use requestID for that? If so, then let's have a try.

don't log objects to remove at all

Agree, log output in this test is horrible.

@mbiryukova please, check on this.

> log error on single object here sequentially during removing (don't wait until all object be tried to delete, can be usefull when error is some timeout errors). But this can require distinguishing multiple deletion from single one in that method Can we use `requestID` for that? If so, then let's have a try. > don't log objects to remove at all Agree, log output in this [test](https://git.frostfs.info/TrueCloudLab/s3-tests/src/commit/997f78d58ac7b991e555328953fc8e72d912a303/s3tests_boto3/functional/test_s3.py#L1716) is horrible. @mbiryukova please, check on this.

👀 1

dkirillov commented

2024-02-22 06:43:10 +00:00

Collaborator

Can we use requestID for that? If so, then let's have a try.

No (if I understood you correctly), I thought about new field in DeleteObjectParams.

But if you meant: can we know which log entry belongs current request, yes we can (just use log from request, that already contains request id as field)

> Can we use requestID for that? If so, then let's have a try. No (if I understood you correctly), I thought about new field in `DeleteObjectParams`. But if you meant: can we know which log entry belongs current request, yes we can (just use log from request, that already contains request id as field)

mbiryukova force-pushed feature/delete_multiple_objects_log_record from fb6bf25b0d to c0fb9b7512

2024-02-22 11:44:31 +00:00

Compare

mbiryukova force-pushed feature/delete_multiple_objects_log_record from c0fb9b7512 to 522ff191d2

2024-02-22 11:50:35 +00:00

Compare

dkirillov approved these changes 2024-02-26 06:59:48 +00:00

alexvanin approved these changes 2024-02-28 14:30:42 +00:00

alexvanin left a comment

Owner

@mbiryukova can you give an example of log output of S3 gateway when one of the delete operation fails? You can artificially add an error in code while deleting second object to demonstrate it.

mbiryukova commented

2024-02-28 16:01:00 +00:00

Poster

Collaborator

Log when deleting two objects, one of which is locked

2024-02-28T18:54:47.308+0300    info    middleware/reqinfo.go:222       request start   {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "host": "localhost:8091", "remote_host": "127.0.0.1"}
2024-02-28T18:54:47.321+0300    info    layer/layer.go:800      resolve bucket  {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "cid": "3w72ftv3vmzHvvV6mND8odLoNag2ZPa2FHUkWhywDVcr"}
2024-02-28T18:54:47.334+0300    debug   layer/tagging.go:184    get tree node   {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "cid": "3w72ftv3vmzHvvV6mND8odLoNag2ZPa2FHUkWhywDVcr", "oid": "7eRUdgKaEt4PmFUGFznw9PzXfRUAYLRD2cfpA9zdML7e"}
2024-02-28T18:54:47.393+0300    debug   layer/tagging.go:184    get tree node   {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "cid": "3w72ftv3vmzHvvV6mND8odLoNag2ZPa2FHUkWhywDVcr", "oid": "GiGuMGnyoohc1yJ2cAK9BuUfVnwgwBLeELdG6DJct3jR"}
2024-02-28T18:54:47.399+0300    error   layer/layer.go:770      couldn't delete object  {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "object": "object2:GiGuMGnyoohc1yJ2cAK9BuUfVnwgwBLeELdG6DJct3jR", "error": "mark object removal via connection pool: remove object via client 192.168.130.71:8080: delete object on client: status: code = 1024 message = incomplete object PUT by placement: could not write header: (*putsvc.remoteTarget) could not put single object to [/dns4/s04.frostfs.devenv/tcp/8082/tls /dns4/s04.frostfs.devenv/tcp/8080]: put single object via client: status: code = 1024 message = incomplete object PUT by placement: could not delete objects from tombstone locally: status: code = 2050 message = object is locked"}
2024-02-28T18:54:47.399+0300    info    middleware/response.go:325      request end     {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "method": "DeleteMultipleObjects", "bucket": "bucket", "object": "", "status": 200, "description": "OK"}

Log when deleting two objects, one of which is locked ``` 2024-02-28T18:54:47.308+0300 info middleware/reqinfo.go:222 request start {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "host": "localhost:8091", "remote_host": "127.0.0.1"} 2024-02-28T18:54:47.321+0300 info layer/layer.go:800 resolve bucket {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "cid": "3w72ftv3vmzHvvV6mND8odLoNag2ZPa2FHUkWhywDVcr"} 2024-02-28T18:54:47.334+0300 debug layer/tagging.go:184 get tree node {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "cid": "3w72ftv3vmzHvvV6mND8odLoNag2ZPa2FHUkWhywDVcr", "oid": "7eRUdgKaEt4PmFUGFznw9PzXfRUAYLRD2cfpA9zdML7e"} 2024-02-28T18:54:47.393+0300 debug layer/tagging.go:184 get tree node {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "cid": "3w72ftv3vmzHvvV6mND8odLoNag2ZPa2FHUkWhywDVcr", "oid": "GiGuMGnyoohc1yJ2cAK9BuUfVnwgwBLeELdG6DJct3jR"} 2024-02-28T18:54:47.399+0300 error layer/layer.go:770 couldn't delete object {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "bucket": "bucket", "object": "object2:GiGuMGnyoohc1yJ2cAK9BuUfVnwgwBLeELdG6DJct3jR", "error": "mark object removal via connection pool: remove object via client 192.168.130.71:8080: delete object on client: status: code = 1024 message = incomplete object PUT by placement: could not write header: (*putsvc.remoteTarget) could not put single object to [/dns4/s04.frostfs.devenv/tcp/8082/tls /dns4/s04.frostfs.devenv/tcp/8080]: put single object via client: status: code = 1024 message = incomplete object PUT by placement: could not delete objects from tombstone locally: status: code = 2050 message = object is locked"} 2024-02-28T18:54:47.399+0300 info middleware/response.go:325 request end {"request_id": "69132c9e-baf4-4afa-9707-773d82d51844", "method": "DeleteMultipleObjects", "bucket": "bucket", "object": "", "status": 200, "description": "OK"} ```