search

nspcc-dev / neofs-node

NeoFS is a decentralized distributed object storage integrated with the Neo blockchain
https://fs.neo.org
GNU General Public License v3.0
31 stars 38 forks source link

Evacuate tests fail #2860

Closed carpawell closed 3 weeks ago

carpawell commented 1 month ago

Expected Behavior

Tests are OK.

Current Behavior

--- FAIL: TestEvacuateShard (0.24s)
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   opening...  {"shard_id": "DBto3z9gDCW33YdHmLXdHN"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   created directory for Metabase  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "path": "/tmp/2834443257/0.metabase"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   opened boltDB instance for Metabase {"shard_id": "DBto3z9gDCW33YdHmLXdHN"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   checking metabase version   {"shard_id": "DBto3z9gDCW33YdHmLXdHN"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   opening...  {"shard_id": "EceU6VFwyaHVKhATvdgpUL"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   created directory for Metabase  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "path": "/tmp/2834443257/1.metabase"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   opened boltDB instance for Metabase {"shard_id": "EceU6VFwyaHVKhATvdgpUL"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   checking metabase version   {"shard_id": "EceU6VFwyaHVKhATvdgpUL"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   opening...  {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.216Z DEBUG   created directory for Metabase  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "path": "/tmp/2834443257/2.metabase"}
    logger.go:146: 2024-06-03T13:49:41.217Z DEBUG   opened boltDB instance for Metabase {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.217Z DEBUG   checking metabase version   {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.217Z DEBUG   initializing... {"shard_id": "DBto3z9gDCW33YdHmLXdHN"}
    logger.go:146: 2024-06-03T13:49:41.217Z DEBUG   initializing... {"shard_id": "EceU6VFwyaHVKhATvdgpUL"}
    logger.go:146: 2024-06-03T13:49:41.218Z DEBUG   initializing... {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.220Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "Eg5pzkyzTdRRuJDvMiBGVvVNw5ckYiM6bSB5G2DQTK6f/BDsBtenDUywgf71k5bYwiRNDitdUZwnW3xWcxPTxLcYw", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.233Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "Eg5pzkyzTdRRuJDvMiBGVvVNw5ckYiM6bSB5G2DQTK6f/BDsBtenDUywgf71k5bYwiRNDitdUZwnW3xWcxPTxLcYw", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.234Z INFO    local object storage operation  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "address": "3FmCwtAX3jwQELuS2Amt8NfW1wAYVt9JRZNEDprPYkjS/CuHg3pi91H14CGnETaNMboApTDKnX9jqaptj4gpSEWxa", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.246Z INFO    local object storage operation  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "address": "3FmCwtAX3jwQELuS2Amt8NfW1wAYVt9JRZNEDprPYkjS/CuHg3pi91H14CGnETaNMboApTDKnX9jqaptj4gpSEWxa", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.248Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "2tRK8b2vuzz2D4dzG8LyjTSHCE1qtLvZjEYJH6aS2u9f/3HxJUXcYiDBZnJfpqjTcSBvNQubri6TiqF7Ndzh1zmYG", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.261Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "2tRK8b2vuzz2D4dzG8LyjTSHCE1qtLvZjEYJH6aS2u9f/3HxJUXcYiDBZnJfpqjTcSBvNQubri6TiqF7Ndzh1zmYG", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.262Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "AGt7PqiAAvAxpmoCU6ePDZ7uMoQwMCLH8e5XxEdD8SBJ/DGnpi5LiZPvN91mjgGpL5rAwpLWbwmDhceWxeGV1Ztwd", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.[275](https://github.com/nspcc-dev/neofs-node/actions/runs/9351374091/job/25736983542?pr=2859#step:4:276)Z   INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "AGt7PqiAAvAxpmoCU6ePDZ7uMoQwMCLH8e5XxEdD8SBJ/DGnpi5LiZPvN91mjgGpL5rAwpLWbwmDhceWxeGV1Ztwd", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.[277](https://github.com/nspcc-dev/neofs-node/actions/runs/9351374091/job/25736983542?pr=2859#step:4:278)Z   INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "CfZjSt2uRt5weRWCiamFvdTqRmWqiKWAFZ9MM3HsUohi/C9jB58cwKSBTa3BecAp1qzYEfDkmubW1kEpY74MmRx8b", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.290Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "CfZjSt2uRt5weRWCiamFvdTqRmWqiKWAFZ9MM3HsUohi/C9jB58cwKSBTa3BecAp1qzYEfDkmubW1kEpY74MmRx8b", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.292Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "9D3UcjxYTBdjg2Sk61ityuUnjJXFUxPvzXYYZCXbsEFb/9yMiKJ3D4BeVg4D9aK7DhRvTSwqch9TNmCQkm1jydxHW", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.305Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "9D3UcjxYTBdjg2Sk61ityuUnjJXFUxPvzXYYZCXbsEFb/9yMiKJ3D4BeVg4D9aK7DhRvTSwqch9TNmCQkm1jydxHW", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.307Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "GNdVy2p9TQt36c9tZceFfSXhZKcRKiWTkV3cT4aS3k3i/9c2UzkgDmyECxjwkYg1wVMtWeEyJUkXn3tcsiyf4apCK", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.320Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "GNdVy2p9TQt36c9tZceFfSXhZKcRKiWTkV3cT4aS3k3i/9c2UzkgDmyECxjwkYg1wVMtWeEyJUkXn3tcsiyf4apCK", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.322Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "HvrYbHQVQD7Z6V8PHovsU2SrkbREkhnV4FcBBhqKoSwF/FLSbnQVk4vAfoYnV3t8d6tvAsb6A9vrrn2LRzYoiYk6k", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.334Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "HvrYbHQVQD7Z6V8PHovsU2SrkbREkhnV4FcBBhqKoSwF/FLSbnQVk4vAfoYnV3t8d6tvAsb6A9vrrn2LRzYoiYk6k", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.336Z INFO    local object storage operation  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "address": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.350Z INFO    local object storage operation  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "address": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.353Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "5JdAXTNBzKH55PJ2tgFJw22cAPxq7waRu7xG1TSLaGdi/FWpzB8CtTnPNaq5hg67QEXTeL8cP9kk5vhASbrpbFnBe", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.365Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "5JdAXTNBzKH55PJ2tgFJw22cAPxq7waRu7xG1TSLaGdi/FWpzB8CtTnPNaq5hg67QEXTeL8cP9kk5vhASbrpbFnBe", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.367Z INFO    local object storage operation  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "address": "5pDJdohqsdyNqqT53JwSdUbDRWW6T7y98yRWjnroxiKr/Hpf8QW1she2PYDckTKhaVnYS3cWu9AD28vR1eKRzTae", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.379Z INFO    local object storage operation  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "address": "5pDJdohqsdyNqqT53JwSdUbDRWW6T7y98yRWjnroxiKr/Hpf8QW1she2PYDckTKhaVnYS3cWu9AD28vR1eKRzTae", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.383Z INFO    setting shard mode  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "old_mode": "READ_WRITE", "new_mode": "READ_ONLY"}
    logger.go:146: 2024-06-03T13:49:41.383Z DEBUG   closing...  {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.383Z DEBUG   opening...  {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.383Z DEBUG   initializing... {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.383Z DEBUG   created directory for Metabase  {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "path": "/tmp/[283](https://github.com/nspcc-dev/neofs-node/actions/runs/9351374091/job/25736983542?pr=2859#step:4:284)4443257/2.metabase"}
    logger.go:146: 2024-06-03T13:49:41.383Z DEBUG   opened boltDB instance for Metabase {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.383Z DEBUG   checking metabase version   {"shard_id": "99WayA7TkS4KKHpSiV3yWa"}
    logger.go:146: 2024-06-03T13:49:41.383Z INFO    shard mode set successfully {"shard_id": "99WayA7TkS4KKHpSiV3yWa", "mode": "READ_ONLY"}
    logger.go:146: 2024-06-03T13:49:41.383Z INFO    started shards evacuation   {"shard_ids": ["99WayA7TkS4KKHpSiV3yWa"]}
    logger.go:146: 2024-06-03T13:49:41.384Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "3FmCwtAX3jwQELuS2Amt8NfW1wAYVt9JRZNEDprPYkjS/CuHg3pi91H14CGnETaNMboApTDKnX9jqaptj4gpSEWxa", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.397Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "3FmCwtAX3jwQELuS2Amt8NfW1wAYVt9JRZNEDprPYkjS/CuHg3pi91H14CGnETaNMboApTDKnX9jqaptj4gpSEWxa", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.397Z DEBUG   object is moved to another shard    {"from": "99WayA7TkS4KKHpSiV3yWa", "to": "DBto3z9gDCW33YdHmLXdHN", "addr": "3FmCwtAX3jwQELuS2Amt8NfW1wAYVt9JRZNEDprPYkjS/CuHg3pi91H14CGnETaNMboApTDKnX9jqaptj4gpSEWxa"}
    logger.go:146: 2024-06-03T13:49:41.398Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "5pDJdohqsdyNqqT53JwSdUbDRWW6T7y98yRWjnroxiKr/Hpf8QW1she2PYDckTKhaVnYS3cWu9AD28vR1eKRzTae", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.411Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "5pDJdohqsdyNqqT53JwSdUbDRWW6T7y98yRWjnroxiKr/Hpf8QW1she2PYDckTKhaVnYS3cWu9AD28vR1eKRzTae", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.411Z DEBUG   object is moved to another shard    {"from": "99WayA7TkS4KKHpSiV3yWa", "to": "EceU6VFwyaHVKhATvdgpUL", "addr": "5pDJdohqsdyNqqT53JwSdUbDRWW6T7y98yRWjnroxiKr/Hpf8QW1she2PYDckTKhaVnYS3cWu9AD28vR1eKRzTae"}
    logger.go:146: 2024-06-03T13:49:41.412Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.425Z INFO    local object storage operation  {"shard_id": "EceU6VFwyaHVKhATvdgpUL", "address": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.425Z DEBUG   object is moved to another shard    {"from": "99WayA7TkS4KKHpSiV3yWa", "to": "EceU6VFwyaHVKhATvdgpUL", "addr": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB"}
    logger.go:146: 2024-06-03T13:49:41.425Z INFO    finished shards evacuation  {"shard_ids": ["99WayA7TkS4KKHpSiV3yWa"]}
    logger.go:146: 2024-06-03T13:49:41.428Z INFO    started shards evacuation   {"shard_ids": ["99WayA7TkS4KKHpSiV3yWa"]}
    logger.go:146: 2024-06-03T13:49:41.432Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB", "op": "PUT", "type": "fstree", "storage_id": ""}
    logger.go:146: 2024-06-03T13:49:41.445Z INFO    local object storage operation  {"shard_id": "DBto3z9gDCW33YdHmLXdHN", "address": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB", "op": "metabase PUT"}
    logger.go:146: 2024-06-03T13:49:41.445Z DEBUG   object is moved to another shard    {"from": "99WayA7TkS4KKHpSiV3yWa", "to": "DBto3z9gDCW33YdHmLXdHN", "addr": "BEG2pD7HofkAKhAQJV2LkE4ji83rU3XWtFaJy7BxmzcN/BJKrkY7fh1kDUjdZL6uZky99Ar1B4CbTNwR422Xa6ecB"}
    logger.go:146: 2024-06-03T13:49:41.445Z INFO    finished shards evacuation  {"shard_ids": ["99WayA7TkS4KKHpSiV3yWa"]}
    evacuate_test.go:116: 
            Error Trace:    /home/runner/work/neofs-node/neofs-node/pkg/local_object_storage/engine/evacuate_test.go:116
            Error:          Not equal: 
                            expected: 0
                            actual  : 1
            Test:           TestEvacuateShard
FAIL
FAIL    github.com/nspcc-dev/neofs-node/pkg/local_object_storage/engine 4.[295](https://github.com/nspcc-dev/neofs-node/actions/runs/9351374091/job/25736983542?pr=2859#step:4:296)s

Possible Solution

No idea.

Steps to Reproduce (for bugs)

Not sure it is stable.

Context

https://github.com/nspcc-dev/neofs-node/actions/runs/9351374091/job/25736983542?pr=2859

roman-khimov commented 1 month ago

Yup, noticed this several times as well.

carpawell commented 3 weeks ago

1000 tries to reproduce locally (~10h total), no errors. Need to think about runners and what is happening there.