TrueCloudLab
/
frostfs-node
19
1
Fork 20
Code Issues 93 Pull Requests 9 Actions Releases Activity

Command object hash range returned object not found #891

New Issue
Closed
opened 2023-12-28 11:08:58 +00:00 by anikeev-yadro · 6 comments
anikeev-yadro commented 2023-12-28 11:08:58 +00:00

Expected Behavior

Command object hash range should return hash on object range

Current Behavior

Command object hash range returned object not found

Steps to Reproduce (for bugs)

1.Create container

COMMAND: frostfs-cli --config /jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/wallet_config.yml container create --rpc-endpoint '10.78.130.135:8080' --wallet '/jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/TemporaryDir/f2ac42ff-9940-438f-a5d1-2d19b0b95e75.json' --await --policy 'REP 2 IN X CBF 1 SELECT 4 FROM * AS X'
RETCODE: 0

STDOUT:
container ID: FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj
awaiting...
container has been persisted on sidechain

STDERR:

Start / End / Elapsed	 08:09:56.971663 / 08:10:02.379764 / 0:00:05.408101

2.Put object

COMMAND: frostfs-cli --config /jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/wallet_config.yml object put --rpc-endpoint '10.78.130.144:8080' --wallet '/jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/TemporaryDir/f2ac42ff-9940-438f-a5d1-2d19b0b95e75.json' --cid 'FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj' --file 'TemporaryDir/e1d981b5-fefc-4145-98f6-627f5b4ffc77' --no-progress
RETCODE: 0

STDOUT:
[TemporaryDir/e1d981b5-fefc-4145-98f6-627f5b4ffc77] Object successfully stored
  OID: 6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM
  CID: FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj

STDERR:

Start / End / Elapsed	 08:10:02.769914 / 08:10:03.209652 / 0:00:00.439738

3.Try to get hash of object range

COMMAND: frostfs-cli --config /jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/wallet_config.yml object hash --rpc-endpoint '10.78.130.135:8080' --wallet '/jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/TemporaryDir/f2ac42ff-9940-438f-a5d1-2d19b0b95e75.json' --cid 'FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj' --oid '6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM' --range '0:250'
RETCODE: 1

STDOUT:
rpc error: read payload hashes via client: status: code = 2049 message = object not found

STDERR:

Start / End / Elapsed	 08:11:47.917467 / 08:11:48.349309 / 0:00:00.431842

4.In the logs we saw the following messages about this OID.

дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.308Z        debug        get/get.go:88        serving request...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z        debug        get/local.go:33        local get failed        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z        debug        get/get.go:109        operation finished with error        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z        debug        get/container.go:19        trying to execute in container...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "netmap lookup depth": 0}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z        debug        get/container.go:47        process epoch        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "number": 239}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z        debug        get/remote.go:19        processing node...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.316Z        debug        get/remote.go:37        remote call failed        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.316Z        debug        get/remote.go:19        processing node...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.324Z        debug        get/remote.go:37        remote call failed        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.325Z        debug        get/remote.go:19        processing node...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.336Z        debug        get/remote.go:37        remote call failed        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.336Z        debug        get/remote.go:19        processing node...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.345Z        debug        get/remote.go:37        remote call failed        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.345Z        debug        get/container.go:64        no more nodes, abort placement iteration        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.345Z        debug        get/get.go:109        operation finished with error        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"}

дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.604Z        debug        get/get.go:88        serving request...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z        debug        get/local.go:33        local get failed        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"}
дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z        debug        get/get.go:109        operation finished with error        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"}
дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z        debug        get/container.go:19        trying to execute in container...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "netmap lookup depth": 0}
дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z        debug        get/container.go:47        process epoch        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "number": 239}
дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.607Z        debug        get/remote.go:19        processing node...        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.611Z        debug        get/container.go:88        completing the operation        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}
дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.611Z        debug        get/get.go:100        operation finished successfully        {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false}

Context

Autotest testsuites.object.test_object_api.TestObjectApi#test_object_get_range_hash.
Test was success on 4 nodes systems on cloud and HW.

Regression

No

Version

FrostFS Storage node
Version: v0.37.0-25-ge39db638
GoVersion: go1.20.5

Your Environment

32 nodes
cloud

## Expected Behavior Command `object hash range` should return hash on object range ## Current Behavior Command `object hash range` returned `object not found` ## Steps to Reproduce (for bugs) 1.Create container ``` COMMAND: frostfs-cli --config /jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/wallet_config.yml container create --rpc-endpoint '10.78.130.135:8080' --wallet '/jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/TemporaryDir/f2ac42ff-9940-438f-a5d1-2d19b0b95e75.json' --await --policy 'REP 2 IN X CBF 1 SELECT 4 FROM * AS X' RETCODE: 0 STDOUT: container ID: FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj awaiting... container has been persisted on sidechain STDERR: Start / End / Elapsed 08:09:56.971663 / 08:10:02.379764 / 0:00:05.408101 ``` 2.Put object ``` COMMAND: frostfs-cli --config /jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/wallet_config.yml object put --rpc-endpoint '10.78.130.144:8080' --wallet '/jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/TemporaryDir/f2ac42ff-9940-438f-a5d1-2d19b0b95e75.json' --cid 'FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj' --file 'TemporaryDir/e1d981b5-fefc-4145-98f6-627f5b4ffc77' --no-progress RETCODE: 0 STDOUT: [TemporaryDir/e1d981b5-fefc-4145-98f6-627f5b4ffc77] Object successfully stored OID: 6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM CID: FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj STDERR: Start / End / Elapsed 08:10:02.769914 / 08:10:03.209652 / 0:00:00.439738 ``` 3.Try to get hash of object range ``` COMMAND: frostfs-cli --config /jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/wallet_config.yml object hash --rpc-endpoint '10.78.130.135:8080' --wallet '/jenkins/workspace/release_v1.5_sbercloud_tatlin_object_test/tmp.IwNaHU1OOz/frostfs-testcases/TemporaryDir/f2ac42ff-9940-438f-a5d1-2d19b0b95e75.json' --cid 'FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj' --oid '6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM' --range '0:250' RETCODE: 1 STDOUT: rpc error: read payload hashes via client: status: code = 2049 message = object not found STDERR: Start / End / Elapsed 08:11:47.917467 / 08:11:48.349309 / 0:00:00.431842 ``` 4.In the logs we saw the following messages about this OID. ``` дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.308Z debug get/get.go:88 serving request... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z debug get/local.go:33 local get failed {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z debug get/get.go:109 operation finished with error {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z debug get/container.go:19 trying to execute in container... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "netmap lookup depth": 0} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z debug get/container.go:47 process epoch {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "number": 239} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.309Z debug get/remote.go:19 processing node... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.316Z debug get/remote.go:37 remote call failed {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.316Z debug get/remote.go:19 processing node... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.324Z debug get/remote.go:37 remote call failed {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.325Z debug get/remote.go:19 processing node... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.336Z debug get/remote.go:37 remote call failed {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.336Z debug get/remote.go:19 processing node... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.345Z debug get/remote.go:37 remote call failed {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.345Z debug get/container.go:64 no more nodes, abort placement iteration {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:11:48 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:11:48.345Z debug get/get.go:109 operation finished with error {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"} ``` ``` дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.604Z debug get/get.go:88 serving request... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z debug get/local.go:33 local get failed {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"} дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z debug get/get.go:109 operation finished with error {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "status: code = 2049 message = object not found"} дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z debug get/container.go:19 trying to execute in container... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "netmap lookup depth": 0} дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.606Z debug get/container.go:47 process epoch {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false, "number": 239} дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.607Z debug get/remote.go:19 processing node... {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.611Z debug get/container.go:88 completing the operation {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 08:12:01 dkarmanov-node1 frostfs-node[954155]: 2023-12-28T08:12:01.611Z debug get/get.go:100 operation finished successfully {"component": "Object.Get service", "request": "GET_RANGE", "address": "FyvrBG7dXrLQvpxoR3umQvSsp1SnDFXXSJgCxTPTrqEj/6aFyDygLvsC4ZpKHJN54Xc9ZRv2gDCTR3SSH1crRjuBM", "raw": false, "local": false, "with session": false, "with bearer": false} ``` ## Context Autotest `testsuites.object.test_object_api.TestObjectApi#test_object_get_range_hash`. Test was success on 4 nodes systems on cloud and HW. ## Regression No ## Version ``` FrostFS Storage node Version: v0.37.0-25-ge39db638 GoVersion: go1.20.5 ``` ## Your Environment 32 nodes cloud
anikeev-yadro added the
bug
triage
 labels 2023-12-28 11:08:58 +00:00
dstepanov-yadro commented 2023-12-28 12:50:51 +00:00
Collaborator

Reproduced on 32 node cluster:

#!/bin/bash

set -euxo pipefail

cid=$(frostfs-cli container create -r localhost:8080 --wallet ./wallet.json --policy "REP 2 IN X CBF 1 SELECT 4 FROM * AS X" --config empty_pass.yml --await | grep 'container ID:' | awk '{ print $3 }')

oid=$(frostfs-cli object put -r localhost:8080 --wallet ./wallet.json --file ./8KB.bin --config empty_pass.yml --cid $cid --no-progress | grep 'OID:' | awk '{ print $2 }')

frostfs-cli object head -r localhost:8080 --wallet ./wallet.json --config empty_pass.yml --cid $cid --oid $oid --raw

frostfs-cli object hash -r localhost:8080 --wallet ./wallet.json --config empty_pass.yml --cid $cid --oid $oid --range '0:250
Reproduced on 32 node cluster: ``` #!/bin/bash set -euxo pipefail cid=$(frostfs-cli container create -r localhost:8080 --wallet ./wallet.json --policy "REP 2 IN X CBF 1 SELECT 4 FROM * AS X" --config empty_pass.yml --await | grep 'container ID:' | awk '{ print $3 }') oid=$(frostfs-cli object put -r localhost:8080 --wallet ./wallet.json --file ./8KB.bin --config empty_pass.yml --cid $cid --no-progress | grep 'OID:' | awk '{ print $2 }') frostfs-cli object head -r localhost:8080 --wallet ./wallet.json --config empty_pass.yml --cid $cid --oid $oid --raw frostfs-cli object hash -r localhost:8080 --wallet ./wallet.json --config empty_pass.yml --cid $cid --oid $oid --range '0:250 ```
dstepanov-yadro commented 2023-12-28 13:15:27 +00:00
Collaborator

I added some extra logs:

func (r *request) getRemote(ctx context.Context, rs remoteStorage, info client.NodeInfo) (*objectSDK.Object, error) {
	key, err := r.key()
	if err != nil {
		return nil, err
	}

	var idOwner user.ID
	user.IDFromKey(&idOwner, key.PublicKey)
	r.log.Logger.Info("user id", zap.Stringer("pk", idOwner))

	if r.isForwardingEnabled() {
		r.log.Logger.Info("forwarding enabled")
		return rs.ForwardRequest(ctx, info, r.prm.forwarder)
	}
	r.log.Logger.Info("forwarding disabled")

Looks like HEAD request executed with owner's signature:

дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.049Z        info        get/remote.go:76        forwarding enabled        {"component": "Object.Get service", "request": "HEAD", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": true, "local": false, "with session": false, "with bearer": false}

дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.056Z        debug        get/container.go:88        completing the operation        {"component": "Object.Get service", "request": "HEAD", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": true, "local": false, "with session": false, "with bearer": false}

дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.056Z        debug        get/get.go:100        operation finished successfully        {"component": "Object.Get service", "request": "HEAD", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": true, "local": false, "with session": false, "with bearer": false}

But GET_RANGE request executed with node's signature:

дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.736Z        info        get/remote.go:79        forwarding disabled        {"component": "Object.Get service", "request": "GET_RANGE", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": false, "local": false, "with session": false, "with bearer": false}

дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.744Z        debug        get/remote.go:38        remote call failed        {"component": "Object.Get service", "request": "GET_RANGE", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"}
I added some extra logs: ``` func (r *request) getRemote(ctx context.Context, rs remoteStorage, info client.NodeInfo) (*objectSDK.Object, error) { key, err := r.key() if err != nil { return nil, err } var idOwner user.ID user.IDFromKey(&idOwner, key.PublicKey) r.log.Logger.Info("user id", zap.Stringer("pk", idOwner)) if r.isForwardingEnabled() { r.log.Logger.Info("forwarding enabled") return rs.ForwardRequest(ctx, info, r.prm.forwarder) } r.log.Logger.Info("forwarding disabled") ``` Looks like HEAD request executed with owner's signature: ``` дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.049Z info get/remote.go:76 forwarding enabled {"component": "Object.Get service", "request": "HEAD", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": true, "local": false, "with session": false, "with bearer": false} дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.056Z debug get/container.go:88 completing the operation {"component": "Object.Get service", "request": "HEAD", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": true, "local": false, "with session": false, "with bearer": false} дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.056Z debug get/get.go:100 operation finished successfully {"component": "Object.Get service", "request": "HEAD", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": true, "local": false, "with session": false, "with bearer": false} ``` But GET_RANGE request executed with node's signature: ``` дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.736Z info get/remote.go:79 forwarding disabled {"component": "Object.Get service", "request": "GET_RANGE", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": false, "local": false, "with session": false, "with bearer": false} дек 28 13:10:59 dkarmanov-node1 frostfs-node[3635536]: 2023-12-28T13:10:59.744Z debug get/remote.go:38 remote call failed {"component": "Object.Get service", "request": "GET_RANGE", "address": "8AAN38FQfoKQtdsKivZfFF3f8SawCkYg6Dwtpt86muAZ/EJFTRGviSgEfC4XEa1NSc6tJPeJAAZxmQpTGsJbSSLWU", "raw": false, "local": false, "with session": false, "with bearer": false, "error": "read object header: status: code = 2048 message = access to object operation denied"} ```
fyrchik commented 2023-12-29 05:28:32 +00:00
Owner

For get_range it is expected: we create a new request if an object is missing locally, because GetRange request is allowed to contain multiple ranges, each of which may be redirected to a different node.

For `get_range` it is expected: we _create_ a new request if an object is missing locally, because `GetRange` request is allowed to contain multiple ranges, each of which may be redirected to a different node.
dstepanov-yadro commented 2023-12-29 09:32:05 +00:00
Collaborator

But from user's POV it looks strange: user can download object, but can't get range hash

But from user's POV it looks strange: user can download object, but can't get range hash
fyrchik commented 2023-12-29 09:38:49 +00:00
Owner

With eACL this is by design, we do not prevent shooting ourselves in the foot.

With eACL this is by design, we do not prevent shooting ourselves in the foot.
dstepanov-yadro self-assigned this 2024-01-09 08:06:23 +00:00
fyrchik added this to the v0.38.0 milestone 2024-01-11 17:30:45 +00:00
fyrchik added
frostfs-node
 and removed
triage
 labels 2024-01-11 17:30:53 +00:00
dstepanov-yadro commented 2024-01-12 14:55:34 +00:00
Collaborator

Now non-container node forwards get range hash request to one of container-nodes.

Now non-container node forwards get range hash request to one of container-nodes.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
fix/cli_control_targets
master
support/v0.38
support/v0.37
support/v0.36
support/v0.34
support/v0.30
support/v0.27
v0.39.0
v0.38.6
v0.38.5
v0.38.4
v0.38.3
v0.38.2
v0.38.1
v0.38.0
v0.38.0-rc.2
v0.38.0-rc.1
v0.37.0
v0.37.0-rc.1
v0.36.0
v0.34.0
Labels
Clear labels   
P0

Highest   
P1

High   
P2

Medium   
P3

Low   
badger

Badger DB related issues   
frostfs-adm
   
frostfs-cli
   
frostfs-ir
   
frostfs-lens
   
frostfs-node
   
good first issue

Good for newcomers   
triage
  
Infrastructure

Infrastructure, Automation, CI/CD or DevOps related stuff   
blocked

The issue or PR is blocked by something   
bug

Something is not working   
config

Configuration format update or breaking change   
discussion

Talking about something in order to reach a decision or to exchange ideas   
documentation

Documentation related   
duplicate

This issue or pull request already exists   
enhancement

New feature   
go

Language features adoption   
help wanted

Extra attention is needed   
internal
   
invalid

Something is wrong   
kludge

This is a kludge and we know it   
observability

Related to metrics, tracing and logs   
perfomance

Perfomance related   
question

More information is needed   
refactoring

Refactoring   
wontfix

This won't be fixed
No Label
P0
P1
P2
P3
badger
frostfs-adm
frostfs-cli
frostfs-ir
frostfs-lens
frostfs-node
good first issue
triage
Infrastructure
blocked
bug
config
discussion
documentation
duplicate
enhancement
go
help wanted
internal
invalid
kludge
observability
perfomance
question
refactoring
wontfix
Milestone
Clear milestone
No items
No Milestone
v0.38.0
Assignees
Clear assignees
No Assignees
dstepanov-yadro
3 Participants
Notifications
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: TrueCloudLab/frostfs-node#891
There is no content yet.
Delete Branch "%!s(<nil>)"

Deleting a branch is permanent. Although the deleted branch may exist for a short time before cleaning up, in most cases it CANNOT be undone. Continue?