Node with NeoFS BlockFetcher hanging

[AliceInHunterland]

Current Behavior

I can't interrupt the process.

(base) ekaterinapavlova@MacBook-Air-4 neo-go % ./bin/neo-go node -t
2024-11-22T12:08:46.999+0300    INFO    MaxValidUntilBlockIncrement is not set or wrong, using default value    {"MaxValidUntilBlockIncrement": 5760}
2024-11-22T12:08:47.002+0300    INFO    restoring blockchain    {"version": "0.2.12"}
2024-11-22T12:08:47.087+0300    INFO    starting service        {"service": "Prometheus", "endpoint": ":2112"}
2024-11-22T12:08:47.087+0300    INFO    service hasn't started since it's disabled      {"service": "Pprof"}
2024-11-22T12:08:47.087+0300    INFO    ExtensiblePoolSize is not set or wrong, using default value     {"ExtensiblePoolSize": 20}
2024-11-22T12:08:47.087+0300    INFO    MaxIteratorResultItems is not set or wrong, setting default value       {"MaxIteratorResultItems": 100}
2024-11-22T12:08:47.087+0300    INFO    MaxFindResultItems is not set or wrong, setting default value   {"MaxFindResultItems": 100}
2024-11-22T12:08:47.087+0300    INFO    MaxFindStorageResultItems is not set or wrong, setting default value    {"MaxFindStorageResultItems": 50}
2024-11-22T12:08:47.087+0300    INFO    MaxNEP11Tokens is not set or wrong, setting default value       {"MaxNEP11Tokens": 100}
2024-11-22T12:08:47.087+0300    INFO    MaxRequestBodyBytes is not set or wong, setting default value   {"MaxRequestBodyBytes": 5242880}
2024-11-22T12:08:47.087+0300    INFO    MaxRequestHeaderBytes is not set or wong, setting default value {"MaxRequestHeaderBytes": 1048576}
2024-11-22T12:08:47.087+0300    INFO    MaxWebSocketClients is not set or wrong, setting default value  {"MaxWebSocketClients": 64}
2024-11-22T12:08:47.087+0300    INFO    node started    {"blockHeight": 310818, "headerHeight": 310818}
2024-11-22T12:08:47.087+0300    INFO    starting NeoFS BlockFetcher service

    _   ____________        __________
   / | / / ____/ __ \      / ____/ __ \
  /  |/ / __/ / / / /_____/ / __/ / / /
 / /|  / /___/ /_/ /_____/ /_/ / /_/ /
/_/ |_/_____/\____/      \____/\____/

/NEO-GO:0.106.4-pre-249-gcfc30dd2/

2024-11-22T12:08:47.348+0300    INFO    starting rpc-server     {"endpoint": ":20332"}
2024-11-22T12:08:47.938+0300    INFO    new peer connected      {"addr": "35.188.199.101:20333", "peerCount": 1}
2024-11-22T12:08:48.136+0300    INFO    started protocol        {"addr": "35.188.199.101:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 444624179}
2024-11-22T12:08:48.160+0300    INFO    new peer connected      {"addr": "35.238.26.128:20333", "peerCount": 2}
2024-11-22T12:08:48.209+0300    INFO    new peer connected      {"addr": "35.192.59.217:20333", "peerCount": 3}
2024-11-22T12:08:48.245+0300    INFO    new peer connected      {"addr": "34.133.235.69:20333", "peerCount": 4}
2024-11-22T12:08:48.330+0300    INFO    new peer connected      {"addr": "34.124.145.177:20333", "peerCount": 5}
2024-11-22T12:08:48.360+0300    INFO    started protocol        {"addr": "35.238.26.128:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 376107787}
2024-11-22T12:08:48.388+0300    INFO    started protocol        {"addr": "35.192.59.217:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 1624722693}
2024-11-22T12:08:48.416+0300    INFO    started protocol        {"addr": "34.133.235.69:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 1747048648}
2024-11-22T12:08:48.557+0300    INFO    started protocol        {"addr": "34.124.145.177:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 1649744297}
2024-11-22T12:08:48.640+0300    INFO    new peer connected      {"addr": "34.124.145.177:20333", "peerCount": 6}
2024-11-22T12:08:48.640+0300    INFO    new peer connected      {"addr": "49.12.226.190:21333", "peerCount": 7}
2024-11-22T12:08:48.660+0300    INFO    new peer connected      {"addr": "34.87.58.201:20333", "peerCount": 8}
2024-11-22T12:08:48.667+0300    INFO    new peer connected      {"addr": "34.16.114.243:20333", "peerCount": 9}
2024-11-22T12:08:48.711+0300    INFO    started protocol        {"addr": "49.12.226.190:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008772, "id": 336185100}
2024-11-22T12:08:48.749+0300    INFO    new peer connected      {"addr": "35.226.51.66:20333", "peerCount": 10}
2024-11-22T12:08:48.844+0300    INFO    new peer connected      {"addr": "35.192.59.217:20333", "peerCount": 11}
2024-11-22T12:08:48.844+0300    INFO    started protocol        {"addr": "34.16.114.243:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 2002327254}
2024-11-22T12:08:48.865+0300    INFO    peer disconnected       {"addr": "34.124.145.177:20333", "error": "unexpected empty payload: CMDVersion", "peerCount": 10}
2024-11-22T12:08:48.884+0300    INFO    started protocol        {"addr": "34.87.58.201:20333", "userAgent": "/Neo:3.7.4+7f227a3026fadeb9723280e6f961b6f29b0f8a7a/", "startHeight": 5008772, "id": 633305305}
2024-11-22T12:08:48.908+0300    INFO    new peer connected      {"addr": "34.133.235.69:20333", "peerCount": 11}
2024-11-22T12:08:48.929+0300    INFO    started protocol        {"addr": "35.226.51.66:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 282803997}
2024-11-22T12:08:48.969+0300    INFO    new peer connected      {"addr": "34.66.159.103:20333", "peerCount": 12}
2024-11-22T12:08:48.969+0300    INFO    new peer connected      {"addr": "85.159.213.129:20333", "peerCount": 13}
2024-11-22T12:08:48.969+0300    INFO    new peer connected      {"addr": "35.232.23.196:20333", "peerCount": 14}
2024-11-22T12:08:49.011+0300    INFO    new peer connected      {"addr": "35.240.246.253:20333", "peerCount": 15}
2024-11-22T12:08:49.029+0300    INFO    new peer connected      {"addr": "34.126.65.191:20333", "peerCount": 16}
2024-11-22T12:08:49.029+0300    INFO    peer disconnected       {"addr": "35.192.59.217:20333", "error": "unexpected empty payload: CMDVersion", "peerCount": 15}
2024-11-22T12:08:49.053+0300    INFO    started protocol        {"addr": "85.159.213.129:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 1228628534}
2024-11-22T12:08:49.072+0300    INFO    new peer connected      {"addr": "65.108.90.74:21333", "peerCount": 16}
2024-11-22T12:08:49.117+0300    INFO    peer disconnected       {"addr": "34.133.235.69:20333", "error": "unexpected empty payload: CMDVersion", "peerCount": 15}
2024-11-22T12:08:49.117+0300    INFO    new peer connected      {"addr": "49.12.229.165:20333", "peerCount": 16}
2024-11-22T12:08:49.140+0300    INFO    new peer connected      {"addr": "170.64.152.72:21333", "peerCount": 17}
2024-11-22T12:08:49.141+0300    INFO    started protocol        {"addr": "65.108.90.74:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008772, "id": 2079489540}
2024-11-22T12:08:49.160+0300    INFO    started protocol        {"addr": "34.66.159.103:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 935092544}
2024-11-22T12:08:49.160+0300    INFO    started protocol        {"addr": "35.232.23.196:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 1222516029}
2024-11-22T12:08:49.184+0300    INFO    new peer connected      {"addr": "5.78.81.79:21333", "peerCount": 18}
2024-11-22T12:08:49.201+0300    INFO    started protocol        {"addr": "49.12.229.165:20333", "userAgent": "/NEO-GO:0.106.2/", "startHeight": 5008772, "id": 1194913023}
2024-11-22T12:08:49.252+0300    INFO    started protocol        {"addr": "35.240.246.253:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 1302806530}
2024-11-22T12:08:49.252+0300    INFO    started protocol        {"addr": "34.126.65.191:20333", "userAgent": "/Neo:3.7.5+2fdf1bb8a9562ad0472d0e0926c91b7ce21f5243/", "startHeight": 5008772, "id": 299926172}
2024-11-22T12:08:49.296+0300    INFO    new peer connected      {"addr": "159.203.28.78:21333", "peerCount": 19}
2024-11-22T12:08:49.421+0300    INFO    started protocol        {"addr": "5.78.81.79:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008772, "id": 4148519239}
2024-11-22T12:08:49.422+0300    INFO    new peer connected      {"addr": "167.71.212.120:21333", "peerCount": 20}
2024-11-22T12:08:49.458+0300    INFO    started protocol        {"addr": "159.203.28.78:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008772, "id": 3486734457}
2024-11-22T12:08:49.521+0300    INFO    started protocol        {"addr": "170.64.152.72:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008772, "id": 2774110789}
2024-11-22T12:08:49.644+0300    INFO    new peer connected      {"addr": "34.124.145.177:20333", "peerCount": 21}
2024-11-22T12:08:49.672+0300    INFO    started protocol        {"addr": "167.71.212.120:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008772, "id": 3946254236}
2024-11-22T12:08:49.879+0300    INFO    peer disconnected       {"addr": "34.124.145.177:20333", "error": "unexpected empty payload: CMDVersion", "peerCount": 20}
2024-11-22T12:08:52.862+0300    INFO    new peer connected      {"addr": "34.133.235.69:20333", "peerCount": 21}
2024-11-22T12:08:53.041+0300    INFO    peer disconnected       {"addr": "34.133.235.69:20333", "error": "unexpected empty payload: CMDVersion", "peerCount": 20}
2024-11-22T12:08:55.324+0300    INFO    new peer connected      {"addr": "34.133.235.69:20333", "peerCount": 21}
2024-11-22T12:08:55.490+0300    INFO    peer disconnected       {"addr": "34.133.235.69:20333", "error": "unexpected empty payload: CMDVersion", "peerCount": 20}
2024-11-22T12:10:47.346+0300    INFO    peer disconnected       {"addr": "34.66.159.103:20333", "error": "ping/pong timeout", "peerCount": 19}
2024-11-22T12:15:47.353+0300    INFO    peer disconnected       {"addr": "34.133.235.69:20333", "error": "ping/pong timeout", "peerCount": 18}
2024-11-22T12:20:02.773+0300    INFO    peer disconnected       {"addr": "35.238.26.128:20333", "error": "unexpected empty payload: CMDVersion", "peerCount": 17}
^C2024-11-22T12:34:10.404+0300  INFO    shutting down server    {"peers": 17}
2024-11-22T12:34:10.406+0300    INFO    shutting down NeoFS BlockFetcher service        {"force": true}
^C^C2024-11-22T12:47:17.487+0300        INFO    peer disconnected       {"addr": "167.71.212.120:21333", "error": "ping/pong timeout", "peerCount": 16}
2024-11-22T12:47:17.491+0300    INFO    peer disconnected       {"addr": "49.12.226.190:21333", "error": "ping/pong timeout", "peerCount": 15}
2024-11-22T12:49:47.493+0300    INFO    peer disconnected       {"addr": "65.108.90.74:21333", "error": "ping/pong timeout", "peerCount": 14}
^C^C^C^C2024-11-22T12:55:47.540+0300    INFO    peer disconnected       {"addr": "35.188.199.101:20333", "error": "ping/pong timeout", "peerCount": 13}
2024-11-22T12:55:47.680+0300    INFO    new peer connected      {"addr": "65.108.90.74:21333", "peerCount": 14}
2024-11-22T12:55:47.741+0300    INFO    started protocol        {"addr": "65.108.90.74:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008946, "id": 2079489540}
2024-11-22T12:55:48.145+0300    INFO    new peer connected      {"addr": "116.203.249.217:21333", "peerCount": 15}
2024-11-22T12:55:48.264+0300    INFO    started protocol        {"addr": "116.203.249.217:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008946, "id": 4183069731}
2024-11-22T12:56:04.067+0300    INFO    new peer connected      {"addr": "167.71.212.120:21333", "peerCount": 16}
2024-11-22T12:56:04.349+0300    INFO    started protocol        {"addr": "167.71.212.120:21333", "userAgent": "/NEO-GO:0.106.3/", "startHeight": 5008947, "id": 3946254236}
2024-11-22T12:57:17.542+0300    INFO    peer disconnected       {"addr": "35.226.51.66:20333", "error": "ping/pong timeout", "peerCount": 15}

Expected Behavior

Blocks downloaded, the process can be easily finished. After 2024-11-22T12:34:10.406+0300 INFO shutting down NeoFS BlockFetcher service {"force": true} the node should live her usual life

Steps to Reproduce

config:

NeoFSBlockFetcher:
   Enabled: true
   Addresses:
     - st1.storage.fs.neo.org:8080
     - st2.storage.fs.neo.org:8080
     - st3.storage.fs.neo.org:8080
     - st4.storage.fs.neo.org:8080
   Timeout: 10m
   DownloaderWorkersCount: 2000
   OIDBatchSize: 8000
   BQueueSize: 16000 # must be larger than OIDBatchSize; recommended to be 2*OIDBatchSize or 3*OIDBatchSize
   SkipIndexFilesSearch: false
   IndexFileSize: 128000
   ContainerID: "87JRc7vyWcjW8uS32LMoLTAj4ckCzFZWfKbacjU3sAob"
   BlockAttribute: "Block"
   IndexFileAttribute: "Index"

Context

Blocks in the container were checked previously. But it should be rechecked. Also not full SEARCH result -could be the reason.

Your Environment

master cdbc026