storage engine initialization takes too long

[532910]

8:16:39  neofs-node/main.go:76  initializing storage engine service...
8:23:01  writecache/init.go:14  filling flush marks for objects in FSTree        {"shard_id": "YWVQLsdMz451ShJzUUKqD2"}
8:23:01  writecache/init.go:25  filling flush marks for objects in database        {"shard_id": "YWVQLsdMz451ShJzUUKqD2"}
8:23:01  writecache/init.go:60  finished updating flush marks        {"shard_id": "YWVQLsdMz451ShJzUUKqD2"}
8:23:55  writecache/init.go:14  filling flush marks for objects in FSTree        {"shard_id": "XidSLGUWrwRTFALB3tpD6p"}
8:23:55  writecache/init.go:25  filling flush marks for objects in database        {"shard_id": "XidSLGUWrwRTFALB3tpD6p"}
8:23:55  writecache/init.go:60  finished updating flush marks        {"shard_id": "XidSLGUWrwRTFALB3tpD6p"}
8:23:55  neofs-node/main.go:78  storage engine service has been successfully initialized
8:23:55  neofs-node/main.go:76  initializing gRPC service...

[roman-khimov]

How much data does this node have? Number of shards, sizes, number of files in them?

[fyrchik]

It is a known problem with writecache:

1. After hard-reset some objects may be present in cache but not in the main storage (actually, also true for a simple shutdown).
2. To know which of them can be removed, we must check individually whether each of them was flushed.
3. This check takes time proportional to the amount of objects in a write-cache.

I thought there was a GH issue, but I cannot find it now. One of the approaches to fix this is to initialize cache asynchronously (start check in a background -> return ErrInitializing for modifying operations during it -> finish check).

[fyrchik]

To give you some numbers, it can take ~40 minutes on a dedicated server with ~10 shards and ~100GB cache, so it is worth fixing IMO.

[532910]

this issue is about the first start, when no write-cache exist at all

How much data does this node have? Number of shards, sizes, number of files in them?

it has no data, 2 shards

[roman-khimov]

@fyrchik, I don't see any issue tracking this, do we have it? Because @532910 problem is a different one.

[fyrchik]

@532910 has the initialization finished at some point? If not, this can be related to a recent deadlock in the morph client (aka subscribe without channel readers).

[532910]

yes, it works fine, only initialization takes too long

[vvarg229]

This is reproduced on dev-env of the current version:
https:/nspcc-dev/neofs-dev-env/blob/2d67bc26f76ed072a5a093d03661b9a072f35360/.env
Logs

On the dev-env issue is solved by changing the storage healthchecks timeouts in https:/nspcc-dev/neofs-dev-env/blob/2d67bc26f76ed072a5a093d03661b9a072f35360/services/storage/docker-compose.yml file to a larger value, for example:

    healthcheck:
      test: ["CMD-SHELL", "/healthcheck.sh"]
      interval: 5s
      timeout: 5s
      retries: 5
      start_period: 20s

It is important to note that this only reproduced on a Debian 11 machine with kernel version 5.10.0-21-amd64.
On a more recent Ubuntu 22.10 with kernel 5.19.0-38-generic the issue does not reproduce.

[roman-khimov]

Is it still an issue? Shouldn't be.

[vvarg229]

Is it still an issue? Shouldn't be.

Looks like fixed at nspcc-dev/neofs-dev-env#251

[roman-khimov]

Seems to be obsolete in init part. Write cache is #2337.