Cannot create object right after container start up #17

Closed
opened 2025-12-28 18:11:11 +00:00 by sami · 8 comments
Owner

Originally created by @mialbu on GitHub (Jan 23, 2023).

With the latest to provide neofs-aio in one single image (commit 74b925abde) I've run into problems when creating an object within ~2 minutes of neofs-aio container start up (after some time passes the object creation workes as expected). I haven't run into that problem with the second to last commit (fd041257f7).

I start up the neofs-aio container successfully and run tick.epoch before any other code is running. While I have issues with object creation, every other interaction works just fine. This includes the following methods of the Golang client:

  • container Put
  • container Get
  • container Delete
  • container List
  • accounting BalanceGet
  • netmap EndpointInfo
  • netmap NetworkInfo

I am using neofs-sdk-go in a shared library. Specifically, the error appears when the ObjectWriter calls Close() here. The exact error that is returned is type *apistatus.ServerInternal with value status: code = 1024 message = not enough nodes to SELECT from.

For completeness, the container I try to store the object to has a policy with 1 replica and a backupfactor of 0. The complete container information is the following by using neofs-api-java:

image

Using that container for all object related integration tests I've written have worked fine with the former commit in neofs-aio and imho should not have had any affect on this issue.

Finally, the logs I get from docker logs neofs-aio:

❯ docker logs aio
=> Try to restore blocks before running node
2023-01-20T11:37:03.302Z	INFO	initial gas supply is not set or wrong, setting default value	{"InitialGASSupply": "52000000"}
2023-01-20T11:37:03.303Z	INFO	P2PNotaryRequestPayloadPool size is not set or wrong, setting default value	{"P2PNotaryRequestPayloadPoolSize": 1000}
2023-01-20T11:37:03.303Z	INFO	MaxBlockSize is not set or wrong, setting default value	{"MaxBlockSize": 262144}
2023-01-20T11:37:03.303Z	INFO	MaxBlockSystemFee is not set or wrong, setting default value	{"MaxBlockSystemFee": 900000000000}
2023-01-20T11:37:03.303Z	INFO	MaxTransactionsPerBlock is not set or wrong, using default value	{"MaxTransactionsPerBlock": 512}
2023-01-20T11:37:03.303Z	INFO	MaxValidUntilBlockIncrement is not set or wrong, using default value	{"MaxValidUntilBlockIncrement": 86400}
2023-01-20T11:37:03.303Z	INFO	NativeActivations are not set, using default values
2023-01-20T11:37:03.303Z	INFO	Hardforks are not set, using default value
2023-01-20T11:37:03.307Z	INFO	no storage version found! creating genesis block
2023-01-20T11:37:03.308Z	INFO	initialize restore	{"start": 0, "height": 0, "skip": 0, "count": 84}
2023-01-20T11:37:03.308Z	INFO	service is running	{"service": "Prometheus", "endpoint": ":20001"}
2023-01-20T11:37:03.308Z	INFO	service hasn't started since it's disabled	{"service": "Pprof"}
2023-01-20T11:37:03.412Z	INFO	runtime log	{"tx": "9e53234d1fe8996cfbc93f8df656f21769abd11454c0f1753e68405d77fbf9b6", "script": "ee70ca2cff1073b0335c0b4062edbaa7f59ad629", "msg": "audit contract initialized"}
2023-01-20T11:37:03.416Z	INFO	runtime log	{"tx": "eb157170f07ad21269ea06b57902b3ab3e8ec563ec43fb64c764ab23bf837a04", "script": "f7a77b58e2581cb3f363977295ff870e42c42555", "msg": "balance contract initialized"}
2023-01-20T11:37:03.419Z	INFO	runtime log	{"tx": "b5f945bdd776d9afa5b8bfd4543b07d1ebc78116a1c1c071f1fe590ff7053ae7", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "container contract initialized"}
2023-01-20T11:37:03.425Z	INFO	runtime log	{"tx": "3e47fdb0bcadb60fb80b3500e81dd0a2505b9eeaed418813447873bbdaae16b7", "script": "af4681232a16511654d007ee851a799a3475b551", "msg": "neofsid contract initialized"}
2023-01-20T11:37:03.427Z	INFO	runtime log	{"tx": "710a68e90da07ab98f1fd1842b6d94d88603b13906d367f772f71245cfc5c9bf", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "netmap contract initialized"}
2023-01-20T11:37:03.429Z	INFO	runtime log	{"tx": "9b294401c893b53965a8e45d0cb9af8243558633ca6497367d670c57b517212c", "script": "7a2b472632f30c0bd841dbe88252096f4e1eccd4", "msg": "proxy contract initialized"}
2023-01-20T11:37:03.435Z	INFO	runtime log	{"tx": "fcbcf790e99522a1d214d710feecaa7d9fd2ef65a050d6751b6d35aaaaf5eebb", "script": "f567d868746cd46c2f3a2c46a9e454cd56a1be1e", "msg": "reputation contract initialized"}
2023-01-20T11:37:03.440Z	INFO	runtime log	{"tx": "d392d194e44fa7dfad9d60e2c51a411f6cf5e16ff9ed3b11e1ca572b13707eaf", "script": "73cf92b4a0a52009605d19d1dbc67db05d243662", "msg": "Az contract initialized"}
2023-01-20T11:37:03.452Z	INFO	shutting down service	{"service": "Prometheus", "endpoint": ":20001"}
2023-01-20T11:37:03.485Z	INFO	persisted to disk	{"blocks": 83, "keys": 2500, "headerHeight": 83, "blockHeight": 83, "took": "23.91621ms"}
2023-01-20T11:37:03.520Z	INFO	initial gas supply is not set or wrong, setting default value	{"InitialGASSupply": "52000000"}
2023-01-20T11:37:03.520Z	INFO	P2PNotaryRequestPayloadPool size is not set or wrong, setting default value	{"P2PNotaryRequestPayloadPoolSize": 1000}
2023-01-20T11:37:03.520Z	INFO	MaxBlockSize is not set or wrong, setting default value	{"MaxBlockSize": 262144}
2023-01-20T11:37:03.520Z	INFO	MaxBlockSystemFee is not set or wrong, setting default value	{"MaxBlockSystemFee": 900000000000}
2023-01-20T11:37:03.520Z	INFO	MaxTransactionsPerBlock is not set or wrong, using default value	{"MaxTransactionsPerBlock": 512}
2023-01-20T11:37:03.520Z	INFO	MaxValidUntilBlockIncrement is not set or wrong, using default value	{"MaxValidUntilBlockIncrement": 86400}
2023-01-20T11:37:03.520Z	INFO	NativeActivations are not set, using default values
2023-01-20T11:37:03.520Z	INFO	Hardforks are not set, using default value
2023-01-20T11:37:03.526Z	INFO	restoring blockchain	{"version": "0.2.6"}
2023-01-20T11:37:03.530Z	INFO	ExtensiblePoolSize is not set or wrong, using default value	{"ExtensiblePoolSize": 20}
2023-01-20T11:37:03.530Z	INFO	service is running	{"service": "Prometheus", "endpoint": ":20001"}
2023-01-20T11:37:03.530Z	INFO	service hasn't started since it's disabled	{"service": "Pprof"}
2023-01-20T11:37:04.321Z	INFO	starting rpc-server	{"endpoint": ":30333"}
2023-01-20T11:37:04.322Z	INFO	node started	{"blockHeight": 83, "headerHeight": 83}
2023-01-20T11:37:04.322Z	INFO	node reached synchronized state, starting services
2023-01-20T11:37:04.322Z	INFO	starting state validation service
2023-01-20T11:37:04.322Z	INFO	starting consensus service
2023-01-20T11:37:04.322Z	INFO	initializing dbft	{"height": 84, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:04.322Z	INFO	sending PrepareRequest	{"height": 84, "view": 0}
2023-01-20T11:37:04.322Z	INFO	sending Commit	{"height": 84, "view": 0}
2023-01-20T11:37:04.323Z	INFO	approving block	{"height": 84, "hash": "8a0f6479bd1a842b493a4e7730deb754fde89f4450a71a6842644ed7f7e45496", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "402f0a34509787fdd8bd97a4854026dcdd1e310469684176ec0783f5e889ae36"}
2023-01-20T11:37:04.323Z	INFO	initializing dbft	{"height": 85, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:04.323Z	INFO	starting notary service
2023-01-20T11:37:04.323Z	INFO	RPC server already started

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

/NEO-GO:0.99.4/

2023-01-20T11:37:04.542Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 84, "blockHeight": 84, "took": "10.945575ms"}
2023-01-20T11:37:05.279Z	INFO	Error encountered with rpc request	{"code": -32602, "cause": "invalid method 'GET', please retry with 'POST'", "method": "", "params": "[]"}
2023-01-20T11:37:05.323Z	INFO	sending PrepareRequest	{"height": 85, "view": 0}
2023-01-20T11:37:05.324Z	INFO	sending Commit	{"height": 85, "view": 0}
2023-01-20T11:37:05.324Z	INFO	approving block	{"height": 85, "hash": "14cdfc8e0d630940a1bac215ec1a50f75a4a5f97010a37af214e7531ceff48f8", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "8a0f6479bd1a842b493a4e7730deb754fde89f4450a71a6842644ed7f7e45496"}
2023-01-20T11:37:05.325Z	INFO	initializing dbft	{"height": 86, "view": 0, "index": 0, "role": "Primary"}
Changing ContainerFee configuration value to 0
2023-01-20T11:37:05.535Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 85, "blockHeight": 85, "took": "2.732668ms"}
2023-01-20T11:37:05.745Z	INFO	runtime log	{"tx": "831e72cb192dac5e058af4caa85708102bfcc16a32e92e86fa2d781439ddb3e1", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"}
8f295232280ad323f246e5ba3f64ff987ed810a7f0ab8a4f7b728c57709b4b44
Updating NeoFS epoch to 1
2023-01-20T11:37:06.302Z	INFO	runtime log	{"tx": "3c4c493318cd5c8206f93a433cff861163668d43f11ffc35a66fa02b9fa90edc", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"}
33ac5c793443e76daeb4a4136985f96c5ccc37943e83b380543498d22df29d8e
2023-01-20T11:37:06.326Z	INFO	sending PrepareRequest	{"height": 86, "view": 0}
2023-01-20T11:37:06.326Z	INFO	sending Commit	{"height": 86, "view": 0}
2023-01-20T11:37:06.327Z	INFO	approving block	{"height": 86, "hash": "b8f8861a573b8ef65060243c48f203e8d0ad69a53f37acb2c9faa92bfb818eb4", "tx_count": 2, "merkle": "e9e53bbf7663b18c9bf0e0da862c19fe8b117aed2c7a49d18588ff2e8c97ea09", "prev": "14cdfc8e0d630940a1bac215ec1a50f75a4a5f97010a37af214e7531ceff48f8"}
2023-01-20T11:37:06.327Z	INFO	runtime log	{"tx": "33ac5c793443e76daeb4a4136985f96c5ccc37943e83b380543498d22df29d8e", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"}
2023-01-20T11:37:06.328Z	INFO	runtime log	{"tx": "8f295232280ad323f246e5ba3f64ff987ed810a7f0ab8a4f7b728c57709b4b44", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"}
2023-01-20T11:37:06.329Z	INFO	initializing dbft	{"height": 87, "view": 0, "index": 0, "role": "Primary"}
Changing ContainerAliasFee configuration value to 0
2023-01-20T11:37:06.536Z	INFO	persisted to disk	{"blocks": 1, "keys": 55, "headerHeight": 86, "blockHeight": 86, "took": "3.276584ms"}
2023-01-20T11:37:06.829Z	INFO	runtime log	{"tx": "62d9de9948344dadcfccf8b7b05b09bbb69c0718df73eafa7be3c0769423b384", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"}
c531ae9393de89385ab3a452b53ffcceafc1dcfa4b90f0d60340e41a80e681e6
Updating NeoFS epoch to 2
2023-01-20T11:37:07.327Z	INFO	sending PrepareRequest	{"height": 87, "view": 0}
2023-01-20T11:37:07.328Z	INFO	sending Commit	{"height": 87, "view": 0}
2023-01-20T11:37:07.328Z	INFO	approving block	{"height": 87, "hash": "d58588503ad702685ca5490aa9b694423b1757466c4dba1469386e96447d87e7", "tx_count": 2, "merkle": "aedbdb7d3a41ac3bb5167d87247f37000d94ab7706d32c7053fc1389e0f9a2e3", "prev": "b8f8861a573b8ef65060243c48f203e8d0ad69a53f37acb2c9faa92bfb818eb4"}
2023-01-20T11:37:07.329Z	WARN	contract invocation failed	{"tx": "1fbc77873b0ce9c3e808f9fd30d06e27941a8804008352cb43a5bf034c3c96e4", "block": 87, "error": "at instruction 3051 (THROW): unhandled exception: \"invalid epoch\""}
2023-01-20T11:37:07.329Z	INFO	runtime log	{"tx": "c531ae9393de89385ab3a452b53ffcceafc1dcfa4b90f0d60340e41a80e681e6", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"}
2023-01-20T11:37:07.329Z	INFO	initializing dbft	{"height": 88, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:07.352Z	INFO	runtime log	{"tx": "8d76a02fe4617941d28bc92eb8c9e3976a051ef45cddabb5634bdb7721d5ca2d", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"}
5359651adea872eaabc27e8406e07b8f4b5550b21806e576613250e4c52b3451
2023-01-20T11:37:07.370Z	info	neofs-ir/main.go:123	pprof is disabled, skip
2023-01-20T11:37:07.370Z	info	neofs-ir/main.go:123	prometheus is disabled, skip
2023-01-20T11:37:07.540Z	INFO	persisted to disk	{"blocks": 1, "keys": 43, "headerHeight": 87, "blockHeight": 87, "took": "5.69502ms"}
2023-01-20T11:37:07.810Z	debug	innerring/innerring.go:414	notary support	{"sidechain_enabled": true, "mainchain_enabled": false}
2023-01-20T11:37:07.824Z	debug	settlement/processor.go:66	worker pool for settlement processor successfully initialized	{"capacity": 10}
2023-01-20T11:37:07.824Z	debug	netmap/processor.go:145	netmap worker pool	{"size": 100}
2023-01-20T11:37:07.824Z	debug	event/listener.go:455	registered new event parser	{"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "RemoveNode"}
2023-01-20T11:37:07.824Z	debug	event/listener.go:455	registered new event parser	{"chain": "morph", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:07.824Z	debug	event/listener.go:492	registered new event handler	{"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "RemoveNode"}
2023-01-20T11:37:07.824Z	debug	event/listener.go:492	registered new event handler	{"chain": "morph", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:07.824Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary_type": "addPeer"}
2023-01-20T11:37:07.824Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary_type": "updateState"}
2023-01-20T11:37:07.824Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary type": "addPeer"}
2023-01-20T11:37:07.824Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary type": "updateState"}
2023-01-20T11:37:07.824Z	debug	container/processor.go:91	container worker pool	{"size": 100}
2023-01-20T11:37:07.824Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "put"}
2023-01-20T11:37:07.824Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "putNamed"}
2023-01-20T11:37:07.824Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "delete"}
2023-01-20T11:37:07.824Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "setEACL"}
2023-01-20T11:37:07.824Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "put"}
2023-01-20T11:37:07.824Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "putNamed"}
2023-01-20T11:37:07.824Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "delete"}
2023-01-20T11:37:07.824Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "setEACL"}
2023-01-20T11:37:07.824Z	debug	balance/processor.go:63	balance worker pool	{"size": 100}
2023-01-20T11:37:07.825Z	debug	event/listener.go:455	registered new event parser	{"chain": "morph", "contract": "f7a77b58e2581cb3f363977295ff870e42c42555", "event_type": "Lock"}
2023-01-20T11:37:07.825Z	debug	event/listener.go:492	registered new event handler	{"chain": "morph", "contract": "f7a77b58e2581cb3f363977295ff870e42c42555", "event_type": "Lock"}
2023-01-20T11:37:07.825Z	debug	alphabet/processor.go:68	alphabet worker pool	{"size": 100}
2023-01-20T11:37:07.825Z	debug	reputation/processor.go:74	reputation worker pool	{"size": 100}
2023-01-20T11:37:07.825Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "f567d868746cd46c2f3a2c46a9e454cd56a1be1e", "notary_type": "put"}
2023-01-20T11:37:07.825Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "f567d868746cd46c2f3a2c46a9e454cd56a1be1e", "notary type": "put"}
2023-01-20T11:37:07.825Z	info	event/listener.go:551	registered new event parser	{"chain": "morph", "mempool_type": "added", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "notary_type": "put"}
2023-01-20T11:37:07.825Z	info	event/listener.go:590	registered new event handler	{"chain": "morph", "mempool_type": "added", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "notary type": "put"}
2023-01-20T11:37:07.825Z	debug	event/listener.go:455	registered new event parser	{"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "Delete"}
2023-01-20T11:37:07.825Z	debug	event/listener.go:492	registered new event handler	{"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "Delete"}
2023-01-20T11:37:07.829Z	debug	innerring/innerring.go:1066	read config from blockchain	{"active": true, "alphabet": true, "epoch": 1, "precision": 12, "init_epoch_tick_delta": 237}
2023-01-20T11:37:07.834Z	debug	client/notary.go:181	notary deposit invoke	{"amount": 9569584843895, "expire_at": 628, "vub": 90, "tx_hash": "3444789a39b838901a3d040c535d9063555b442a30186ae77a09462134a7af4d"}
2023-01-20T11:37:07.834Z	info	innerring/notary.go:85	waiting to accept side notary deposit
2023-01-20T11:37:07.834Z	INFO	Error encountered with rpc request	{"code": -100, "cause": "failed to locate application log: key not found", "method": "getapplicationlog", "params": "[3444789a39b838901a3d040c535d9063555b442a30186ae77a09462134a7af4d Application]"}
2023-01-20T11:37:08.330Z	INFO	sending PrepareRequest	{"height": 88, "view": 0}
2023-01-20T11:37:08.330Z	INFO	sending Commit	{"height": 88, "view": 0}
2023-01-20T11:37:08.331Z	INFO	approving block	{"height": 88, "hash": "848b542e5174191facca533a581e74271a47ee9300b28108e51fd9e8e00188b5", "tx_count": 2, "merkle": "7ca3c9c0da622363ebf7f5c7606620dc319f266fb8524187de2cc5b46f910726", "prev": "d58588503ad702685ca5490aa9b694423b1757466c4dba1469386e96447d87e7"}
2023-01-20T11:37:08.332Z	INFO	runtime log	{"tx": "5359651adea872eaabc27e8406e07b8f4b5550b21806e576613250e4c52b3451", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"}
2023-01-20T11:37:08.333Z	INFO	initializing dbft	{"height": 89, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:08.338Z	warn	innerring/state.go:131	can't invoke vote method in alphabet contract	{"alphabet_index": 0, "epoch": 1, "error": "neofs error: chain/client: contract execution finished with state FAULT; exception: at instruction 2404 (THROW): unhandled exception: \"invalid epoch\""}
2023-01-20T11:37:08.339Z	info	neofs-ir/main.go:82	application started	{"version": "v0.34.0"}
2023-01-20T11:37:08.339Z	info	taskmanager/listen.go:15	process routine	{"component": "Audit task manager", "queue_capacity": 100}
2023-01-20T11:37:08.540Z	INFO	persisted to disk	{"blocks": 1, "keys": 55, "headerHeight": 88, "blockHeight": 88, "took": "5.282767ms"}
2023-01-20T11:37:09.305Z	debug	metabase/control.go:25	created directory for Metabase	{"path": "/data/metabase.db"}
2023-01-20T11:37:09.307Z	debug	metabase/control.go:46	opened boltDB instance for Metabase
2023-01-20T11:37:09.308Z	debug	metabase/control.go:48	checking metabase version
2023-01-20T11:37:09.313Z	info	neofs-node/config.go:783	shard attached to engine	{"id": "F7HJwT4ZF1ctyTAs7RNxLJ"}
2023-01-20T11:37:09.314Z	info	neofs-node/main.go:76	initializing storage engine service...
2023-01-20T11:37:09.314Z	debug	blobstor/control.go:12	opening...	{"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"}
2023-01-20T11:37:09.315Z	debug	metabase/control.go:25	created directory for Metabase	{"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ", "path": "/data/metabase.db"}
2023-01-20T11:37:09.315Z	debug	metabase/control.go:46	opened boltDB instance for Metabase	{"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"}
2023-01-20T11:37:09.315Z	debug	metabase/control.go:48	checking metabase version	{"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"}
2023-01-20T11:37:09.315Z	debug	blobstor/control.go:32	initializing...	{"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"}
2023-01-20T11:37:09.315Z	debug	blobovniczatree/control.go:21	initializing Blobovnicza's
2023-01-20T11:37:09.316Z	debug	blobovnicza/control.go:17	creating directory for BoltDB	{"component": "Blobovnicza", "path": "/data/blob/blobovnicza/0/0", "ro": false}
2023-01-20T11:37:09.316Z	debug	blobovnicza/control.go:31	opening BoltDB	{"component": "Blobovnicza", "path": "/data/blob/blobovnicza/0/0", "permissions": "-rwxrwxrwx"}
2023-01-20T11:37:09.321Z	debug	blobovnicza/control.go:47	initializing...	{"component": "Blobovnicza", "object size limit": 1048576, "storage size limit": 1073741824}
2023-01-20T11:37:09.321Z	debug	blobovnicza/control.go:62	creating bucket for size range	{"component": "Blobovnicza", "range": "[0:32768]"}
2023-01-20T11:37:09.321Z	debug	blobovnicza/control.go:62	creating bucket for size range	{"component": "Blobovnicza", "range": "[32769:65536]"}
2023-01-20T11:37:09.321Z	debug	blobovnicza/control.go:62	creating bucket for size range	{"component": "Blobovnicza", "range": "[65537:131072]"}
2023-01-20T11:37:09.321Z	debug	blobovnicza/control.go:62	creating bucket for size range	{"component": "Blobovnicza", "range": "[131073:262144]"}
2023-01-20T11:37:09.321Z	debug	blobovnicza/control.go:62	creating bucket for size range	{"component": "Blobovnicza", "range": "[262145:524288]"}
2023-01-20T11:37:09.321Z	debug	blobovnicza/control.go:62	creating bucket for size range	{"component": "Blobovnicza", "range": "[524289:1048576]"}
2023-01-20T11:37:09.327Z	debug	blobovniczatree/control.go:39	blobovnicza successfully initialized, closing...	{"id": "0/0"}
2023-01-20T11:37:09.327Z	debug	blobovnicza/control.go:89	closing BoltDB	{"component": "Blobovnicza", "path": "/data/blob/blobovnicza/0/0"}
2023-01-20T11:37:09.331Z	info	neofs-node/main.go:78	storage engine service has been successfully initialized
2023-01-20T11:37:09.331Z	info	neofs-node/main.go:76	initializing gRPC service...
2023-01-20T11:37:09.332Z	INFO	sending PrepareRequest	{"height": 89, "view": 0}
2023-01-20T11:37:09.333Z	info	neofs-node/main.go:78	gRPC service has been successfully initialized
2023-01-20T11:37:09.333Z	INFO	sending Commit	{"height": 89, "view": 0}
2023-01-20T11:37:09.333Z	info	neofs-node/main.go:76	initializing netmap service...
2023-01-20T11:37:09.333Z	INFO	approving block	{"height": 89, "hash": "1113f3a7c7ec83691ff5b8b20c7261fd32ba95174c9a45c38d0dd9f02e5cbd8e", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "848b542e5174191facca533a581e74271a47ee9300b28108e51fd9e8e00188b5"}
2023-01-20T11:37:09.335Z	INFO	initializing dbft	{"height": 90, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:09.337Z	debug	innerring/innerring.go:235	new block	{"index": 89}
2023-01-20T11:37:09.357Z	debug	neofs-node/morph.go:83	notary support	{"sidechain_enabled": true}
2023-01-20T11:37:09.357Z	debug	neofs-node/morph.go:98	morph.cache_ttl fetched from network	{"value": 1}
2023-01-20T11:37:09.359Z	info	neofs-node/netmap.go:296	initial network state	{"epoch": 2, "state": "undefined"}
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	netmap service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing accounting service...
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	accounting service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing container service...
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	container service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing session service...
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	session service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing reputation service...
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	reputation service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing notification service...
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	notification service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing object service...
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	object service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing pprof service...
2023-01-20T11:37:09.359Z	info	neofs-node/pprof.go:13	pprof is disabled
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	pprof service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing prometheus service...
2023-01-20T11:37:09.359Z	info	neofs-node/metrics.go:14	prometheus is disabled
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:78	prometheus service has been successfully initialized
2023-01-20T11:37:09.359Z	info	neofs-node/main.go:76	initializing tree service...
2023-01-20T11:37:09.360Z	info	neofs-node/tree.go:39	tree service is not enabled, skip initialization
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:78	tree service has been successfully initialized
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:76	initializing control service...
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:78	control service has been successfully initialized
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:76	initializing morph notifications service...
2023-01-20T11:37:09.360Z	debug	event/listener.go:455	registered new event parser	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:455	registered new event parser	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "PutSuccess"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "PutSuccess"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:455	registered new event parser	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "DeleteSuccess"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "DeleteSuccess"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:455	registered new event parser	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StartEstimation"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StartEstimation"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:455	registered new event parser	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StopEstimation"}
2023-01-20T11:37:09.360Z	debug	event/listener.go:492	registered new event handler	{"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StopEstimation"}
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:78	morph notifications service has been successfully initialized
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:110	starting NATS service...
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:114	NATS service started successfully
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:110	starting gRPC service...
2023-01-20T11:37:09.360Z	info	neofs-node/main.go:110	starting notary service...
2023-01-20T11:37:09.361Z	info	neofs-node/grpc.go:96	start listening gRPC endpoint	{"endpoint": "[::]:8080"}
2023-01-20T11:37:09.366Z	debug	client/notary.go:181	notary deposit invoke	{"amount": 50000000000, "expire_at": 630, "vub": 92, "tx_hash": "33fc5ca79d13014cef8585fd79d6fa2e9e650f5f8bdd2c4c4286fe3b15a3feb9"}
2023-01-20T11:37:09.366Z	INFO	Error encountered with rpc request	{"code": -100, "cause": "failed to locate application log: key not found", "method": "getapplicationlog", "params": "[33fc5ca79d13014cef8585fd79d6fa2e9e650f5f8bdd2c4c4286fe3b15a3feb9 Application]"}
2023-01-20T11:37:09.540Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 89, "blockHeight": 89, "took": "3.644613ms"}
2023-01-20T11:37:10.334Z	INFO	sending PrepareRequest	{"height": 90, "view": 0}
2023-01-20T11:37:10.334Z	INFO	sending Commit	{"height": 90, "view": 0}
2023-01-20T11:37:10.335Z	INFO	approving block	{"height": 90, "hash": "2d52b592230e3f65ebabc2eb38860d21dcd4d0e513f31445bbdafd3eb5d76ad4", "tx_count": 1, "merkle": "b9fea3153bfe86424c2cdd8b5f0f659e2efad679fd8585ef4c01139da75cfc33", "prev": "1113f3a7c7ec83691ff5b8b20c7261fd32ba95174c9a45c38d0dd9f02e5cbd8e"}
2023-01-20T11:37:10.335Z	INFO	initializing dbft	{"height": 91, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:10.336Z	debug	innerring/innerring.go:235	new block	{"index": 90}
2023-01-20T11:37:10.370Z	info	neofs-node/main.go:114	notary service started successfully
2023-01-20T11:37:10.370Z	info	neofs-node/config.go:869	bootstrapping with online state	{"previous": "OFFLINE"}
2023-01-20T11:37:10.376Z	debug	client/notary.go:522	notary request invoked	{"method": "addPeer", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "500bb6b2c06a718c85c4b2ae5e601d3b905f6b49262812a84e460732f98d2076"}
2023-01-20T11:37:10.376Z	info	neofs-node/main.go:128	application started	{"version": "v0.34.0"}
2023-01-20T11:37:10.377Z	info	neofs-node/main.go:110	starting control service...
2023-01-20T11:37:10.377Z	info	neofs-node/main.go:110	starting morph notification service...
2023-01-20T11:37:10.379Z	info	netmap/handlers.go:48	notification	{"type": "add peer"}
2023-01-20T11:37:10.381Z	info	netmap/process_peers.go:65	approving network map candidate	{"key": "022bb4041c50d607ff871dec7e4cd7778388e0ea6849d84ccbd9aa8f32e16a8131"}
aio container started
/usr/bin/neofs-rest-gw
2023-01-20T11:37:10.390Z	debug	client/notary.go:522	notary request invoked	{"method": "addPeerIR", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "bed3e09c07461a0e5dfd07c3dd00f248ce6457acf067b362094c5aa61c108343"}
2023-01-20T11:37:10.410Z	info	neofs-http-gw/app.go:275	no wallet path specified, creating ephemeral key automatically for this run
2023-01-20T11:37:10.410Z	info	neofs-http-gw/app.go:158	add connection	{"address": "localhost:8080", "weight": 1, "priority": 1}
2023-01-20T11:37:10.423Z	debug	session/executor.go:31	serving request...	{"component": "SessionService", "request": "Create"}
2023-01-20T11:37:10.424Z	warn	neofs-http-gw/app.go:478	failed to reload TLS certs	{"error": "tls disabled"}
2023-01-20T11:37:10.428Z	warn	neofs-http-gw/app.go:223	metrics are disabled
2023-01-20T11:37:10.430Z	info	neofs-http-gw/app.go:332	starting application	{"app_name": "neofs-http-gw", "version": "v0.25.0"}
2023-01-20T11:37:10.430Z	info	neofs-http-gw/app.go:513	added path /upload/{cid}
2023-01-20T11:37:10.430Z	info	neofs-http-gw/app.go:516	added path /get/{cid}/{oid}
2023-01-20T11:37:10.430Z	info	neofs-http-gw/app.go:519	added path /get_by_attribute/{cid}/{attr_key}/{attr_val:*}
2023-01-20T11:37:10.431Z	info	neofs-http-gw/app.go:521	added path /zip/{cid}/{prefix}
2023-01-20T11:37:10.431Z	info	metrics/service.go:33	service hasn't started since it's disabled	{"service": "Prometheus"}
2023-01-20T11:37:10.431Z	info	metrics/service.go:33	service hasn't started since it's disabled	{"service": "Pprof"}
2023-01-20T11:37:10.431Z	info	neofs-http-gw/app.go:416	running web server	{"address": "0.0.0.0:8081"}
2023-01-20T11:37:10.540Z	INFO	persisted to disk	{"blocks": 1, "keys": 39, "headerHeight": 90, "blockHeight": 90, "took": "2.950447ms"}
2023-01-20T11:37:10.834Z	info	neofs-rest-gw/config.go:379	added connection peer	{"address": "localhost:8080", "priority": 1, "weight": 1}
2023-01-20T11:37:10.845Z	debug	session/executor.go:31	serving request...	{"component": "SessionService", "request": "Create"}
2023-01-20T11:37:10.914Z	info	metrics/service.go:33	service hasn't started since it's disabled	{"service": "Pprof"}
2023-01-20T11:37:10.914Z	info	metrics/service.go:33	service hasn't started since it's disabled	{"service": "Prometheus"}
2023/01/20 11:37:10 Serving neofs rest gw at http://[::]:8090
2023-01-20T11:37:11.335Z	INFO	sending PrepareRequest	{"height": 91, "view": 0}
2023-01-20T11:37:11.336Z	INFO	sending Commit	{"height": 91, "view": 0}
2023-01-20T11:37:11.336Z	INFO	approving block	{"height": 91, "hash": "2928a5bfb2be7badcbced955ce221dc6da3ad4e75f42a0a5440b2d9beb93279b", "tx_count": 1, "merkle": "052f79c0eb9e889d1d396db5cc0beb8fca20b857376872880b7c77c84f934aba", "prev": "2d52b592230e3f65ebabc2eb38860d21dcd4d0e513f31445bbdafd3eb5d76ad4"}
2023-01-20T11:37:11.337Z	INFO	initializing dbft	{"height": 92, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:11.338Z	debug	subscriber/subscriber.go:137	new notification event from sidechain	{"name": "AddPeerSuccess"}
2023-01-20T11:37:11.338Z	debug	subscriber/subscriber.go:137	new notification event from sidechain	{"name": "AddPeerSuccess"}
2023-01-20T11:37:11.338Z	debug	event/listener.go:326	event parser not set	{"chain": "morph", "script hash LE": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event type": "AddPeerSuccess"}
2023-01-20T11:37:11.338Z	debug	neofs-node/morph.go:238	new block	{"index": 91}
2023-01-20T11:37:11.338Z	debug	event/listener.go:326	event parser not set	{"script hash LE": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event type": "AddPeerSuccess"}
2023-01-20T11:37:11.339Z	debug	innerring/innerring.go:235	new block	{"index": 91}
2023-01-20T11:37:11.542Z	INFO	persisted to disk	{"blocks": 1, "keys": 37, "headerHeight": 91, "blockHeight": 91, "took": "2.739423ms"}
2023-01-20T11:37:12.342Z	INFO	sending PrepareRequest	{"height": 92, "view": 0}
2023-01-20T11:37:12.342Z	INFO	sending Commit	{"height": 92, "view": 0}
2023-01-20T11:37:12.343Z	INFO	approving block	{"height": 92, "hash": "b9fbaa0e2e9263e93a637ed6e4c66be36131dd5b49b2ff5a721f7334ca5a7b2d", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "2928a5bfb2be7badcbced955ce221dc6da3ad4e75f42a0a5440b2d9beb93279b"}
2023-01-20T11:37:12.344Z	INFO	initializing dbft	{"height": 93, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:12.344Z	debug	innerring/innerring.go:235	new block	{"index": 92}
2023-01-20T11:37:12.345Z	debug	neofs-node/morph.go:238	new block	{"index": 92}
2023-01-20T11:37:12.560Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 92, "blockHeight": 92, "took": "10.188473ms"}
2023-01-20T11:37:13.343Z	INFO	sending PrepareRequest	{"height": 93, "view": 0}
2023-01-20T11:37:13.344Z	INFO	sending Commit	{"height": 93, "view": 0}
2023-01-20T11:37:13.344Z	INFO	approving block	{"height": 93, "hash": "f7d392481267289d427efe96b32170e1d90f1f5ab2e11152e2285baf116298d8", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "b9fbaa0e2e9263e93a637ed6e4c66be36131dd5b49b2ff5a721f7334ca5a7b2d"}
2023-01-20T11:37:13.346Z	INFO	initializing dbft	{"height": 94, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:13.347Z	debug	neofs-node/morph.go:238	new block	{"index": 93}
2023-01-20T11:37:13.347Z	debug	innerring/innerring.go:235	new block	{"index": 93}
2023-01-20T11:37:13.567Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 93, "blockHeight": 93, "took": "9.687919ms"}
2023-01-20T11:37:14.344Z	INFO	sending PrepareRequest	{"height": 94, "view": 0}
2023-01-20T11:37:14.345Z	INFO	sending Commit	{"height": 94, "view": 0}
2023-01-20T11:37:14.345Z	INFO	approving block	{"height": 94, "hash": "d4119119b023c665c04295dd114e0abf2756e66fd5d0d766ab893961eb866b2d", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "f7d392481267289d427efe96b32170e1d90f1f5ab2e11152e2285baf116298d8"}
2023-01-20T11:37:14.346Z	INFO	initializing dbft	{"height": 95, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:14.347Z	debug	innerring/innerring.go:235	new block	{"index": 94}
2023-01-20T11:37:14.347Z	debug	neofs-node/morph.go:238	new block	{"index": 94}
2023-01-20T11:37:14.563Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 94, "blockHeight": 94, "took": "4.701267ms"}
2023-01-20T11:37:15.346Z	INFO	sending PrepareRequest	{"height": 95, "view": 0}
2023-01-20T11:37:15.346Z	INFO	sending Commit	{"height": 95, "view": 0}
2023-01-20T11:37:15.347Z	INFO	approving block	{"height": 95, "hash": "122ade736ad6e42e1c7afb70c797ec703cf46cec8e4e2aefbf242d9c8618f200", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "d4119119b023c665c04295dd114e0abf2756e66fd5d0d766ab893961eb866b2d"}
2023-01-20T11:37:15.348Z	INFO	initializing dbft	{"height": 96, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:15.348Z	debug	innerring/innerring.go:235	new block	{"index": 95}
2023-01-20T11:37:15.349Z	debug	neofs-node/morph.go:238	new block	{"index": 95}
2023-01-20T11:37:15.566Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 95, "blockHeight": 95, "took": "7.060374ms"}
2023-01-20T11:37:15.771Z	INFO	runtime log	{"tx": "0e837b43226476d01d4cfaa0f2a2b59e17141a7ae9d67d462fc64270c4972624", "script": "f7a77b58e2581cb3f363977295ff870e42c42555", "msg": "successfully transferred assets"}
2023-01-20T11:37:15.772Z	INFO	runtime log	{"tx": "0e837b43226476d01d4cfaa0f2a2b59e17141a7ae9d67d462fc64270c4972624", "script": "af4681232a16511654d007ee851a799a3475b551", "msg": "key bound to the owner"}
2023-01-20T11:37:15.772Z	INFO	runtime log	{"tx": "0e837b43226476d01d4cfaa0f2a2b59e17141a7ae9d67d462fc64270c4972624", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "added new container"}
2023-01-20T11:37:15.785Z	debug	client/notary.go:522	notary request invoked	{"method": "put", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "7e39e68f2041e951ee6767d4f71ef5ca93be0cc8d8a0a56106adefdf6653a1bf"}
2023-01-20T11:37:15.786Z	info	container/handlers.go:16	notification	{"type": "container put", "id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"}
2023-01-20T11:37:15.797Z	debug	client/notary.go:404	notary request with prepared main TX invoked	{"fallback_valid_for": 40, "tx_hash": "1b51ddc95049401ee9d3ce62790bd5d6f20b51f9a3aa4e821abf43bbe09d4336"}
2023-01-20T11:37:16.348Z	INFO	sending PrepareRequest	{"height": 96, "view": 0}
2023-01-20T11:37:16.348Z	INFO	sending Commit	{"height": 96, "view": 0}
2023-01-20T11:37:16.349Z	INFO	approving block	{"height": 96, "hash": "91ea342cf82c017c72355a5967e46ba624aefdad84b0e675e8c43ccf85482f77", "tx_count": 1, "merkle": "7acaf73a141b9ae021190381c9d7e1df96ae1de3a45ef8d3d4cc3b7bbf0b3408", "prev": "122ade736ad6e42e1c7afb70c797ec703cf46cec8e4e2aefbf242d9c8618f200"}
2023-01-20T11:37:16.351Z	INFO	runtime log	{"tx": "08340bbf7b3bccd4d3f85ea4e31dae96dfe1d7c981031921e09a1b143af7ca7a", "script": "f7a77b58e2581cb3f363977295ff870e42c42555", "msg": "successfully transferred assets"}
2023-01-20T11:37:16.352Z	INFO	runtime log	{"tx": "08340bbf7b3bccd4d3f85ea4e31dae96dfe1d7c981031921e09a1b143af7ca7a", "script": "af4681232a16511654d007ee851a799a3475b551", "msg": "key bound to the owner"}
2023-01-20T11:37:16.352Z	INFO	runtime log	{"tx": "08340bbf7b3bccd4d3f85ea4e31dae96dfe1d7c981031921e09a1b143af7ca7a", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "added new container"}
2023-01-20T11:37:16.353Z	INFO	initializing dbft	{"height": 97, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:16.355Z	debug	subscriber/subscriber.go:137	new notification event from sidechain	{"name": "PutSuccess"}
2023-01-20T11:37:16.355Z	debug	neofs-node/morph.go:238	new block	{"index": 96}
2023-01-20T11:37:16.355Z	error	neofs-node/container.go:92	read newly created container after the notification	{"id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P", "error": "status: code = 3072"}
2023-01-20T11:37:16.356Z	debug	neofs-node/container.go:98	container creation event's receipt	{"id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"}
2023-01-20T11:37:16.357Z	debug	subscriber/subscriber.go:137	new notification event from sidechain	{"name": "Transfer"}
2023-01-20T11:37:16.358Z	debug	event/listener.go:326	event parser not set	{"chain": "morph", "script hash LE": "f7a77b58e2581cb3f363977295ff870e42c42555", "event type": "Transfer"}
2023-01-20T11:37:16.359Z	debug	subscriber/subscriber.go:137	new notification event from sidechain	{"name": "TransferX"}
2023-01-20T11:37:16.359Z	debug	event/listener.go:326	event parser not set	{"chain": "morph", "script hash LE": "f7a77b58e2581cb3f363977295ff870e42c42555", "event type": "TransferX"}
2023-01-20T11:37:16.360Z	debug	innerring/innerring.go:235	new block	{"index": 96}
2023-01-20T11:37:16.361Z	debug	event/listener.go:394	notary parser not set	{"chain": "morph", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "method": "put"}
2023-01-20T11:37:16.566Z	INFO	persisted to disk	{"blocks": 1, "keys": 49, "headerHeight": 96, "blockHeight": 96, "took": "5.623832ms"}
2023-01-20T11:37:17.000Z	debug	session/executor.go:31	serving request...	{"component": "SessionService", "request": "Create"}
2023-01-20T11:37:17.035Z	INFO	runtime log	{"tx": "cc3d1bf533286df96c82f7981b8b19ab2670cd92366a98493835e127645798cd", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "remove container"}
2023-01-20T11:37:17.044Z	debug	client/notary.go:522	notary request invoked	{"method": "delete", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "1b016d77ada85fd9e5b35d0ddd9c98947145d54e815c12665952a5adaae60e92"}
2023-01-20T11:37:17.047Z	info	container/handlers.go:32	notification	{"type": "container delete", "id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"}
2023-01-20T11:37:17.055Z	debug	client/notary.go:404	notary request with prepared main TX invoked	{"fallback_valid_for": 40, "tx_hash": "567f3cbb420a958272b2f01950988e8c0bf07685923ee376a34e6154d361812b"}
2023-01-20T11:37:17.350Z	INFO	sending PrepareRequest	{"height": 97, "view": 0}
2023-01-20T11:37:17.350Z	INFO	sending Commit	{"height": 97, "view": 0}
2023-01-20T11:37:17.352Z	INFO	approving block	{"height": 97, "hash": "eefa343ae235c75d9e528bf1c5e5a957a313c1f4c10a00f7f8a7271e9bffe3e6", "tx_count": 1, "merkle": "ce1282a8af2dd7e3184e8f9602f2cb1846d35db752c1ae1a3374746a78690715", "prev": "91ea342cf82c017c72355a5967e46ba624aefdad84b0e675e8c43ccf85482f77"}
2023-01-20T11:37:17.352Z	INFO	runtime log	{"tx": "150769786a7474331aaec152b75dd34618cbf202968f4e18e3d72dafa88212ce", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "remove container"}
2023-01-20T11:37:17.353Z	INFO	initializing dbft	{"height": 98, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:17.355Z	debug	innerring/innerring.go:235	new block	{"index": 97}
2023-01-20T11:37:17.355Z	debug	event/listener.go:394	notary parser not set	{"chain": "morph", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "method": "delete"}
2023-01-20T11:37:17.356Z	debug	subscriber/subscriber.go:137	new notification event from sidechain	{"name": "DeleteSuccess"}
2023-01-20T11:37:17.356Z	debug	neofs-node/container.go:117	container removal event's receipt	{"id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"}
2023-01-20T11:37:17.357Z	debug	neofs-node/morph.go:238	new block	{"index": 97}
2023-01-20T11:37:17.565Z	INFO	persisted to disk	{"blocks": 1, "keys": 31, "headerHeight": 97, "blockHeight": 97, "took": "3.769574ms"}
2023-01-20T11:37:18.353Z	INFO	sending PrepareRequest	{"height": 98, "view": 0}
2023-01-20T11:37:18.353Z	INFO	sending Commit	{"height": 98, "view": 0}
2023-01-20T11:37:18.353Z	INFO	approving block	{"height": 98, "hash": "5167f23a92c2f21b4e3e6fed3eeda8732e10ac8b06cd1a35fbe5150c26749991", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "eefa343ae235c75d9e528bf1c5e5a957a313c1f4c10a00f7f8a7271e9bffe3e6"}
2023-01-20T11:37:18.354Z	INFO	initializing dbft	{"height": 99, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:18.354Z	debug	innerring/innerring.go:235	new block	{"index": 98}
2023-01-20T11:37:18.355Z	debug	neofs-node/morph.go:238	new block	{"index": 98}
2023-01-20T11:37:18.565Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 98, "blockHeight": 98, "took": "2.542078ms"}
2023-01-20T11:37:19.354Z	INFO	sending PrepareRequest	{"height": 99, "view": 0}
2023-01-20T11:37:19.355Z	INFO	sending Commit	{"height": 99, "view": 0}
2023-01-20T11:37:19.356Z	INFO	approving block	{"height": 99, "hash": "cea57969c015af4d77f18f44aaa474b0e82ec7b93fcaa8d26f03441d626e4efa", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "5167f23a92c2f21b4e3e6fed3eeda8732e10ac8b06cd1a35fbe5150c26749991"}
2023-01-20T11:37:19.357Z	INFO	initializing dbft	{"height": 100, "view": 0, "index": 0, "role": "Primary"}
2023-01-20T11:37:19.358Z	debug	innerring/innerring.go:235	new block	{"index": 99}
2023-01-20T11:37:19.359Z	debug	neofs-node/morph.go:238	new block	{"index": 99}
2023-01-20T11:37:19.567Z	INFO	persisted to disk	{"blocks": 1, "keys": 20, "headerHeight": 99, "blockHeight": 99, "took": "4.489724ms"}
2023-01-20T11:37:20.357Z	INFO	sending PrepareRequest	{"height": 100, "view": 0}
2023-01-20T11:37:20.358Z	INFO	sending Commit	{"height": 100, "view": 0}

@roman-khimov

Originally created by @mialbu on GitHub (Jan 23, 2023). With the latest to provide neofs-aio in one single image (commit 74b925abde8a96ea22882d73b1ad797d30d7d5fb) I've run into problems when creating an object within ~2 minutes of neofs-aio container start up (after some time passes the object creation workes as expected). I haven't run into that problem with the second to last commit (fd041257f7ab74b2e81eeb1a409ce9ce84676c13). I start up the neofs-aio container successfully and run `tick.epoch` before any other code is running. While I have issues with object creation, every other interaction works just fine. This includes the following methods of the Golang client: - container Put - container Get - container Delete - container List - accounting BalanceGet - netmap EndpointInfo - netmap NetworkInfo I am using [neofs-sdk-go](https://github.com/nspcc-dev/neofs-sdk-go) in a shared library. Specifically, the error appears when the `ObjectWriter` calls `Close()` [here](https://github.com/AxLabs/neofs-shared-lib/blob/75929f5f31607714503f114be0ad6b632da550dd/object/object.go#L135). The exact error that is returned is type `*apistatus.ServerInternal` with value `status: code = 1024 message = not enough nodes to SELECT from`. For completeness, the container I try to store the object to has a policy with 1 replica and a backupfactor of 0. The complete container information is the following by using [neofs-api-java](): ![image](https://user-images.githubusercontent.com/53603111/214053736-3c1358bd-5b95-4b54-b3af-c6aac5bbb932.png) Using that container for all object related integration tests I've written have worked fine with the former commit in neofs-aio and imho should not have had any affect on this issue. Finally, the logs I get from `docker logs neofs-aio`: ```shell ❯ docker logs aio => Try to restore blocks before running node 2023-01-20T11:37:03.302Z INFO initial gas supply is not set or wrong, setting default value {"InitialGASSupply": "52000000"} 2023-01-20T11:37:03.303Z INFO P2PNotaryRequestPayloadPool size is not set or wrong, setting default value {"P2PNotaryRequestPayloadPoolSize": 1000} 2023-01-20T11:37:03.303Z INFO MaxBlockSize is not set or wrong, setting default value {"MaxBlockSize": 262144} 2023-01-20T11:37:03.303Z INFO MaxBlockSystemFee is not set or wrong, setting default value {"MaxBlockSystemFee": 900000000000} 2023-01-20T11:37:03.303Z INFO MaxTransactionsPerBlock is not set or wrong, using default value {"MaxTransactionsPerBlock": 512} 2023-01-20T11:37:03.303Z INFO MaxValidUntilBlockIncrement is not set or wrong, using default value {"MaxValidUntilBlockIncrement": 86400} 2023-01-20T11:37:03.303Z INFO NativeActivations are not set, using default values 2023-01-20T11:37:03.303Z INFO Hardforks are not set, using default value 2023-01-20T11:37:03.307Z INFO no storage version found! creating genesis block 2023-01-20T11:37:03.308Z INFO initialize restore {"start": 0, "height": 0, "skip": 0, "count": 84} 2023-01-20T11:37:03.308Z INFO service is running {"service": "Prometheus", "endpoint": ":20001"} 2023-01-20T11:37:03.308Z INFO service hasn't started since it's disabled {"service": "Pprof"} 2023-01-20T11:37:03.412Z INFO runtime log {"tx": "9e53234d1fe8996cfbc93f8df656f21769abd11454c0f1753e68405d77fbf9b6", "script": "ee70ca2cff1073b0335c0b4062edbaa7f59ad629", "msg": "audit contract initialized"} 2023-01-20T11:37:03.416Z INFO runtime log {"tx": "eb157170f07ad21269ea06b57902b3ab3e8ec563ec43fb64c764ab23bf837a04", "script": "f7a77b58e2581cb3f363977295ff870e42c42555", "msg": "balance contract initialized"} 2023-01-20T11:37:03.419Z INFO runtime log {"tx": "b5f945bdd776d9afa5b8bfd4543b07d1ebc78116a1c1c071f1fe590ff7053ae7", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "container contract initialized"} 2023-01-20T11:37:03.425Z INFO runtime log {"tx": "3e47fdb0bcadb60fb80b3500e81dd0a2505b9eeaed418813447873bbdaae16b7", "script": "af4681232a16511654d007ee851a799a3475b551", "msg": "neofsid contract initialized"} 2023-01-20T11:37:03.427Z INFO runtime log {"tx": "710a68e90da07ab98f1fd1842b6d94d88603b13906d367f772f71245cfc5c9bf", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "netmap contract initialized"} 2023-01-20T11:37:03.429Z INFO runtime log {"tx": "9b294401c893b53965a8e45d0cb9af8243558633ca6497367d670c57b517212c", "script": "7a2b472632f30c0bd841dbe88252096f4e1eccd4", "msg": "proxy contract initialized"} 2023-01-20T11:37:03.435Z INFO runtime log {"tx": "fcbcf790e99522a1d214d710feecaa7d9fd2ef65a050d6751b6d35aaaaf5eebb", "script": "f567d868746cd46c2f3a2c46a9e454cd56a1be1e", "msg": "reputation contract initialized"} 2023-01-20T11:37:03.440Z INFO runtime log {"tx": "d392d194e44fa7dfad9d60e2c51a411f6cf5e16ff9ed3b11e1ca572b13707eaf", "script": "73cf92b4a0a52009605d19d1dbc67db05d243662", "msg": "Az contract initialized"} 2023-01-20T11:37:03.452Z INFO shutting down service {"service": "Prometheus", "endpoint": ":20001"} 2023-01-20T11:37:03.485Z INFO persisted to disk {"blocks": 83, "keys": 2500, "headerHeight": 83, "blockHeight": 83, "took": "23.91621ms"} 2023-01-20T11:37:03.520Z INFO initial gas supply is not set or wrong, setting default value {"InitialGASSupply": "52000000"} 2023-01-20T11:37:03.520Z INFO P2PNotaryRequestPayloadPool size is not set or wrong, setting default value {"P2PNotaryRequestPayloadPoolSize": 1000} 2023-01-20T11:37:03.520Z INFO MaxBlockSize is not set or wrong, setting default value {"MaxBlockSize": 262144} 2023-01-20T11:37:03.520Z INFO MaxBlockSystemFee is not set or wrong, setting default value {"MaxBlockSystemFee": 900000000000} 2023-01-20T11:37:03.520Z INFO MaxTransactionsPerBlock is not set or wrong, using default value {"MaxTransactionsPerBlock": 512} 2023-01-20T11:37:03.520Z INFO MaxValidUntilBlockIncrement is not set or wrong, using default value {"MaxValidUntilBlockIncrement": 86400} 2023-01-20T11:37:03.520Z INFO NativeActivations are not set, using default values 2023-01-20T11:37:03.520Z INFO Hardforks are not set, using default value 2023-01-20T11:37:03.526Z INFO restoring blockchain {"version": "0.2.6"} 2023-01-20T11:37:03.530Z INFO ExtensiblePoolSize is not set or wrong, using default value {"ExtensiblePoolSize": 20} 2023-01-20T11:37:03.530Z INFO service is running {"service": "Prometheus", "endpoint": ":20001"} 2023-01-20T11:37:03.530Z INFO service hasn't started since it's disabled {"service": "Pprof"} 2023-01-20T11:37:04.321Z INFO starting rpc-server {"endpoint": ":30333"} 2023-01-20T11:37:04.322Z INFO node started {"blockHeight": 83, "headerHeight": 83} 2023-01-20T11:37:04.322Z INFO node reached synchronized state, starting services 2023-01-20T11:37:04.322Z INFO starting state validation service 2023-01-20T11:37:04.322Z INFO starting consensus service 2023-01-20T11:37:04.322Z INFO initializing dbft {"height": 84, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:04.322Z INFO sending PrepareRequest {"height": 84, "view": 0} 2023-01-20T11:37:04.322Z INFO sending Commit {"height": 84, "view": 0} 2023-01-20T11:37:04.323Z INFO approving block {"height": 84, "hash": "8a0f6479bd1a842b493a4e7730deb754fde89f4450a71a6842644ed7f7e45496", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "402f0a34509787fdd8bd97a4854026dcdd1e310469684176ec0783f5e889ae36"} 2023-01-20T11:37:04.323Z INFO initializing dbft {"height": 85, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:04.323Z INFO starting notary service 2023-01-20T11:37:04.323Z INFO RPC server already started _ ____________ __________ / | / / ____/ __ \ / ____/ __ \ / |/ / __/ / / / /_____/ / __/ / / / / /| / /___/ /_/ /_____/ /_/ / /_/ / /_/ |_/_____/\____/ \____/\____/ /NEO-GO:0.99.4/ 2023-01-20T11:37:04.542Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 84, "blockHeight": 84, "took": "10.945575ms"} 2023-01-20T11:37:05.279Z INFO Error encountered with rpc request {"code": -32602, "cause": "invalid method 'GET', please retry with 'POST'", "method": "", "params": "[]"} 2023-01-20T11:37:05.323Z INFO sending PrepareRequest {"height": 85, "view": 0} 2023-01-20T11:37:05.324Z INFO sending Commit {"height": 85, "view": 0} 2023-01-20T11:37:05.324Z INFO approving block {"height": 85, "hash": "14cdfc8e0d630940a1bac215ec1a50f75a4a5f97010a37af214e7531ceff48f8", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "8a0f6479bd1a842b493a4e7730deb754fde89f4450a71a6842644ed7f7e45496"} 2023-01-20T11:37:05.325Z INFO initializing dbft {"height": 86, "view": 0, "index": 0, "role": "Primary"} Changing ContainerFee configuration value to 0 2023-01-20T11:37:05.535Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 85, "blockHeight": 85, "took": "2.732668ms"} 2023-01-20T11:37:05.745Z INFO runtime log {"tx": "831e72cb192dac5e058af4caa85708102bfcc16a32e92e86fa2d781439ddb3e1", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"} 8f295232280ad323f246e5ba3f64ff987ed810a7f0ab8a4f7b728c57709b4b44 Updating NeoFS epoch to 1 2023-01-20T11:37:06.302Z INFO runtime log {"tx": "3c4c493318cd5c8206f93a433cff861163668d43f11ffc35a66fa02b9fa90edc", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"} 33ac5c793443e76daeb4a4136985f96c5ccc37943e83b380543498d22df29d8e 2023-01-20T11:37:06.326Z INFO sending PrepareRequest {"height": 86, "view": 0} 2023-01-20T11:37:06.326Z INFO sending Commit {"height": 86, "view": 0} 2023-01-20T11:37:06.327Z INFO approving block {"height": 86, "hash": "b8f8861a573b8ef65060243c48f203e8d0ad69a53f37acb2c9faa92bfb818eb4", "tx_count": 2, "merkle": "e9e53bbf7663b18c9bf0e0da862c19fe8b117aed2c7a49d18588ff2e8c97ea09", "prev": "14cdfc8e0d630940a1bac215ec1a50f75a4a5f97010a37af214e7531ceff48f8"} 2023-01-20T11:37:06.327Z INFO runtime log {"tx": "33ac5c793443e76daeb4a4136985f96c5ccc37943e83b380543498d22df29d8e", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"} 2023-01-20T11:37:06.328Z INFO runtime log {"tx": "8f295232280ad323f246e5ba3f64ff987ed810a7f0ab8a4f7b728c57709b4b44", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"} 2023-01-20T11:37:06.329Z INFO initializing dbft {"height": 87, "view": 0, "index": 0, "role": "Primary"} Changing ContainerAliasFee configuration value to 0 2023-01-20T11:37:06.536Z INFO persisted to disk {"blocks": 1, "keys": 55, "headerHeight": 86, "blockHeight": 86, "took": "3.276584ms"} 2023-01-20T11:37:06.829Z INFO runtime log {"tx": "62d9de9948344dadcfccf8b7b05b09bbb69c0718df73eafa7be3c0769423b384", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"} c531ae9393de89385ab3a452b53ffcceafc1dcfa4b90f0d60340e41a80e681e6 Updating NeoFS epoch to 2 2023-01-20T11:37:07.327Z INFO sending PrepareRequest {"height": 87, "view": 0} 2023-01-20T11:37:07.328Z INFO sending Commit {"height": 87, "view": 0} 2023-01-20T11:37:07.328Z INFO approving block {"height": 87, "hash": "d58588503ad702685ca5490aa9b694423b1757466c4dba1469386e96447d87e7", "tx_count": 2, "merkle": "aedbdb7d3a41ac3bb5167d87247f37000d94ab7706d32c7053fc1389e0f9a2e3", "prev": "b8f8861a573b8ef65060243c48f203e8d0ad69a53f37acb2c9faa92bfb818eb4"} 2023-01-20T11:37:07.329Z WARN contract invocation failed {"tx": "1fbc77873b0ce9c3e808f9fd30d06e27941a8804008352cb43a5bf034c3c96e4", "block": 87, "error": "at instruction 3051 (THROW): unhandled exception: \"invalid epoch\""} 2023-01-20T11:37:07.329Z INFO runtime log {"tx": "c531ae9393de89385ab3a452b53ffcceafc1dcfa4b90f0d60340e41a80e681e6", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "configuration has been updated"} 2023-01-20T11:37:07.329Z INFO initializing dbft {"height": 88, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:07.352Z INFO runtime log {"tx": "8d76a02fe4617941d28bc92eb8c9e3976a051ef45cddabb5634bdb7721d5ca2d", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"} 5359651adea872eaabc27e8406e07b8f4b5550b21806e576613250e4c52b3451 2023-01-20T11:37:07.370Z info neofs-ir/main.go:123 pprof is disabled, skip 2023-01-20T11:37:07.370Z info neofs-ir/main.go:123 prometheus is disabled, skip 2023-01-20T11:37:07.540Z INFO persisted to disk {"blocks": 1, "keys": 43, "headerHeight": 87, "blockHeight": 87, "took": "5.69502ms"} 2023-01-20T11:37:07.810Z debug innerring/innerring.go:414 notary support {"sidechain_enabled": true, "mainchain_enabled": false} 2023-01-20T11:37:07.824Z debug settlement/processor.go:66 worker pool for settlement processor successfully initialized {"capacity": 10} 2023-01-20T11:37:07.824Z debug netmap/processor.go:145 netmap worker pool {"size": 100} 2023-01-20T11:37:07.824Z debug event/listener.go:455 registered new event parser {"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "RemoveNode"} 2023-01-20T11:37:07.824Z debug event/listener.go:455 registered new event parser {"chain": "morph", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:07.824Z debug event/listener.go:492 registered new event handler {"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "RemoveNode"} 2023-01-20T11:37:07.824Z debug event/listener.go:492 registered new event handler {"chain": "morph", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:07.824Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary_type": "addPeer"} 2023-01-20T11:37:07.824Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary_type": "updateState"} 2023-01-20T11:37:07.824Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary type": "addPeer"} 2023-01-20T11:37:07.824Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "notary type": "updateState"} 2023-01-20T11:37:07.824Z debug container/processor.go:91 container worker pool {"size": 100} 2023-01-20T11:37:07.824Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "put"} 2023-01-20T11:37:07.824Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "putNamed"} 2023-01-20T11:37:07.824Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "delete"} 2023-01-20T11:37:07.824Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary_type": "setEACL"} 2023-01-20T11:37:07.824Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "put"} 2023-01-20T11:37:07.824Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "putNamed"} 2023-01-20T11:37:07.824Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "delete"} 2023-01-20T11:37:07.824Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "notary type": "setEACL"} 2023-01-20T11:37:07.824Z debug balance/processor.go:63 balance worker pool {"size": 100} 2023-01-20T11:37:07.825Z debug event/listener.go:455 registered new event parser {"chain": "morph", "contract": "f7a77b58e2581cb3f363977295ff870e42c42555", "event_type": "Lock"} 2023-01-20T11:37:07.825Z debug event/listener.go:492 registered new event handler {"chain": "morph", "contract": "f7a77b58e2581cb3f363977295ff870e42c42555", "event_type": "Lock"} 2023-01-20T11:37:07.825Z debug alphabet/processor.go:68 alphabet worker pool {"size": 100} 2023-01-20T11:37:07.825Z debug reputation/processor.go:74 reputation worker pool {"size": 100} 2023-01-20T11:37:07.825Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "f567d868746cd46c2f3a2c46a9e454cd56a1be1e", "notary_type": "put"} 2023-01-20T11:37:07.825Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "f567d868746cd46c2f3a2c46a9e454cd56a1be1e", "notary type": "put"} 2023-01-20T11:37:07.825Z info event/listener.go:551 registered new event parser {"chain": "morph", "mempool_type": "added", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "notary_type": "put"} 2023-01-20T11:37:07.825Z info event/listener.go:590 registered new event handler {"chain": "morph", "mempool_type": "added", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "notary type": "put"} 2023-01-20T11:37:07.825Z debug event/listener.go:455 registered new event parser {"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "Delete"} 2023-01-20T11:37:07.825Z debug event/listener.go:492 registered new event handler {"chain": "morph", "contract": "dd782a8736da57f0d356f659cf63872c5944162d", "event_type": "Delete"} 2023-01-20T11:37:07.829Z debug innerring/innerring.go:1066 read config from blockchain {"active": true, "alphabet": true, "epoch": 1, "precision": 12, "init_epoch_tick_delta": 237} 2023-01-20T11:37:07.834Z debug client/notary.go:181 notary deposit invoke {"amount": 9569584843895, "expire_at": 628, "vub": 90, "tx_hash": "3444789a39b838901a3d040c535d9063555b442a30186ae77a09462134a7af4d"} 2023-01-20T11:37:07.834Z info innerring/notary.go:85 waiting to accept side notary deposit 2023-01-20T11:37:07.834Z INFO Error encountered with rpc request {"code": -100, "cause": "failed to locate application log: key not found", "method": "getapplicationlog", "params": "[3444789a39b838901a3d040c535d9063555b442a30186ae77a09462134a7af4d Application]"} 2023-01-20T11:37:08.330Z INFO sending PrepareRequest {"height": 88, "view": 0} 2023-01-20T11:37:08.330Z INFO sending Commit {"height": 88, "view": 0} 2023-01-20T11:37:08.331Z INFO approving block {"height": 88, "hash": "848b542e5174191facca533a581e74271a47ee9300b28108e51fd9e8e00188b5", "tx_count": 2, "merkle": "7ca3c9c0da622363ebf7f5c7606620dc319f266fb8524187de2cc5b46f910726", "prev": "d58588503ad702685ca5490aa9b694423b1757466c4dba1469386e96447d87e7"} 2023-01-20T11:37:08.332Z INFO runtime log {"tx": "5359651adea872eaabc27e8406e07b8f4b5550b21806e576613250e4c52b3451", "script": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "msg": "process new epoch"} 2023-01-20T11:37:08.333Z INFO initializing dbft {"height": 89, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:08.338Z warn innerring/state.go:131 can't invoke vote method in alphabet contract {"alphabet_index": 0, "epoch": 1, "error": "neofs error: chain/client: contract execution finished with state FAULT; exception: at instruction 2404 (THROW): unhandled exception: \"invalid epoch\""} 2023-01-20T11:37:08.339Z info neofs-ir/main.go:82 application started {"version": "v0.34.0"} 2023-01-20T11:37:08.339Z info taskmanager/listen.go:15 process routine {"component": "Audit task manager", "queue_capacity": 100} 2023-01-20T11:37:08.540Z INFO persisted to disk {"blocks": 1, "keys": 55, "headerHeight": 88, "blockHeight": 88, "took": "5.282767ms"} 2023-01-20T11:37:09.305Z debug metabase/control.go:25 created directory for Metabase {"path": "/data/metabase.db"} 2023-01-20T11:37:09.307Z debug metabase/control.go:46 opened boltDB instance for Metabase 2023-01-20T11:37:09.308Z debug metabase/control.go:48 checking metabase version 2023-01-20T11:37:09.313Z info neofs-node/config.go:783 shard attached to engine {"id": "F7HJwT4ZF1ctyTAs7RNxLJ"} 2023-01-20T11:37:09.314Z info neofs-node/main.go:76 initializing storage engine service... 2023-01-20T11:37:09.314Z debug blobstor/control.go:12 opening... {"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"} 2023-01-20T11:37:09.315Z debug metabase/control.go:25 created directory for Metabase {"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ", "path": "/data/metabase.db"} 2023-01-20T11:37:09.315Z debug metabase/control.go:46 opened boltDB instance for Metabase {"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"} 2023-01-20T11:37:09.315Z debug metabase/control.go:48 checking metabase version {"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"} 2023-01-20T11:37:09.315Z debug blobstor/control.go:32 initializing... {"shard_id": "F7HJwT4ZF1ctyTAs7RNxLJ"} 2023-01-20T11:37:09.315Z debug blobovniczatree/control.go:21 initializing Blobovnicza's 2023-01-20T11:37:09.316Z debug blobovnicza/control.go:17 creating directory for BoltDB {"component": "Blobovnicza", "path": "/data/blob/blobovnicza/0/0", "ro": false} 2023-01-20T11:37:09.316Z debug blobovnicza/control.go:31 opening BoltDB {"component": "Blobovnicza", "path": "/data/blob/blobovnicza/0/0", "permissions": "-rwxrwxrwx"} 2023-01-20T11:37:09.321Z debug blobovnicza/control.go:47 initializing... {"component": "Blobovnicza", "object size limit": 1048576, "storage size limit": 1073741824} 2023-01-20T11:37:09.321Z debug blobovnicza/control.go:62 creating bucket for size range {"component": "Blobovnicza", "range": "[0:32768]"} 2023-01-20T11:37:09.321Z debug blobovnicza/control.go:62 creating bucket for size range {"component": "Blobovnicza", "range": "[32769:65536]"} 2023-01-20T11:37:09.321Z debug blobovnicza/control.go:62 creating bucket for size range {"component": "Blobovnicza", "range": "[65537:131072]"} 2023-01-20T11:37:09.321Z debug blobovnicza/control.go:62 creating bucket for size range {"component": "Blobovnicza", "range": "[131073:262144]"} 2023-01-20T11:37:09.321Z debug blobovnicza/control.go:62 creating bucket for size range {"component": "Blobovnicza", "range": "[262145:524288]"} 2023-01-20T11:37:09.321Z debug blobovnicza/control.go:62 creating bucket for size range {"component": "Blobovnicza", "range": "[524289:1048576]"} 2023-01-20T11:37:09.327Z debug blobovniczatree/control.go:39 blobovnicza successfully initialized, closing... {"id": "0/0"} 2023-01-20T11:37:09.327Z debug blobovnicza/control.go:89 closing BoltDB {"component": "Blobovnicza", "path": "/data/blob/blobovnicza/0/0"} 2023-01-20T11:37:09.331Z info neofs-node/main.go:78 storage engine service has been successfully initialized 2023-01-20T11:37:09.331Z info neofs-node/main.go:76 initializing gRPC service... 2023-01-20T11:37:09.332Z INFO sending PrepareRequest {"height": 89, "view": 0} 2023-01-20T11:37:09.333Z info neofs-node/main.go:78 gRPC service has been successfully initialized 2023-01-20T11:37:09.333Z INFO sending Commit {"height": 89, "view": 0} 2023-01-20T11:37:09.333Z info neofs-node/main.go:76 initializing netmap service... 2023-01-20T11:37:09.333Z INFO approving block {"height": 89, "hash": "1113f3a7c7ec83691ff5b8b20c7261fd32ba95174c9a45c38d0dd9f02e5cbd8e", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "848b542e5174191facca533a581e74271a47ee9300b28108e51fd9e8e00188b5"} 2023-01-20T11:37:09.335Z INFO initializing dbft {"height": 90, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:09.337Z debug innerring/innerring.go:235 new block {"index": 89} 2023-01-20T11:37:09.357Z debug neofs-node/morph.go:83 notary support {"sidechain_enabled": true} 2023-01-20T11:37:09.357Z debug neofs-node/morph.go:98 morph.cache_ttl fetched from network {"value": 1} 2023-01-20T11:37:09.359Z info neofs-node/netmap.go:296 initial network state {"epoch": 2, "state": "undefined"} 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 netmap service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing accounting service... 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 accounting service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing container service... 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 container service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing session service... 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 session service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing reputation service... 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 reputation service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing notification service... 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 notification service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing object service... 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 object service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing pprof service... 2023-01-20T11:37:09.359Z info neofs-node/pprof.go:13 pprof is disabled 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 pprof service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing prometheus service... 2023-01-20T11:37:09.359Z info neofs-node/metrics.go:14 prometheus is disabled 2023-01-20T11:37:09.359Z info neofs-node/main.go:78 prometheus service has been successfully initialized 2023-01-20T11:37:09.359Z info neofs-node/main.go:76 initializing tree service... 2023-01-20T11:37:09.360Z info neofs-node/tree.go:39 tree service is not enabled, skip initialization 2023-01-20T11:37:09.360Z info neofs-node/main.go:78 tree service has been successfully initialized 2023-01-20T11:37:09.360Z info neofs-node/main.go:76 initializing control service... 2023-01-20T11:37:09.360Z info neofs-node/main.go:78 control service has been successfully initialized 2023-01-20T11:37:09.360Z info neofs-node/main.go:76 initializing morph notifications service... 2023-01-20T11:37:09.360Z debug event/listener.go:455 registered new event parser {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event_type": "NewEpoch"} 2023-01-20T11:37:09.360Z debug event/listener.go:455 registered new event parser {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "PutSuccess"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "PutSuccess"} 2023-01-20T11:37:09.360Z debug event/listener.go:455 registered new event parser {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "DeleteSuccess"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "DeleteSuccess"} 2023-01-20T11:37:09.360Z debug event/listener.go:455 registered new event parser {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StartEstimation"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StartEstimation"} 2023-01-20T11:37:09.360Z debug event/listener.go:455 registered new event parser {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StopEstimation"} 2023-01-20T11:37:09.360Z debug event/listener.go:492 registered new event handler {"contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "event_type": "StopEstimation"} 2023-01-20T11:37:09.360Z info neofs-node/main.go:78 morph notifications service has been successfully initialized 2023-01-20T11:37:09.360Z info neofs-node/main.go:110 starting NATS service... 2023-01-20T11:37:09.360Z info neofs-node/main.go:114 NATS service started successfully 2023-01-20T11:37:09.360Z info neofs-node/main.go:110 starting gRPC service... 2023-01-20T11:37:09.360Z info neofs-node/main.go:110 starting notary service... 2023-01-20T11:37:09.361Z info neofs-node/grpc.go:96 start listening gRPC endpoint {"endpoint": "[::]:8080"} 2023-01-20T11:37:09.366Z debug client/notary.go:181 notary deposit invoke {"amount": 50000000000, "expire_at": 630, "vub": 92, "tx_hash": "33fc5ca79d13014cef8585fd79d6fa2e9e650f5f8bdd2c4c4286fe3b15a3feb9"} 2023-01-20T11:37:09.366Z INFO Error encountered with rpc request {"code": -100, "cause": "failed to locate application log: key not found", "method": "getapplicationlog", "params": "[33fc5ca79d13014cef8585fd79d6fa2e9e650f5f8bdd2c4c4286fe3b15a3feb9 Application]"} 2023-01-20T11:37:09.540Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 89, "blockHeight": 89, "took": "3.644613ms"} 2023-01-20T11:37:10.334Z INFO sending PrepareRequest {"height": 90, "view": 0} 2023-01-20T11:37:10.334Z INFO sending Commit {"height": 90, "view": 0} 2023-01-20T11:37:10.335Z INFO approving block {"height": 90, "hash": "2d52b592230e3f65ebabc2eb38860d21dcd4d0e513f31445bbdafd3eb5d76ad4", "tx_count": 1, "merkle": "b9fea3153bfe86424c2cdd8b5f0f659e2efad679fd8585ef4c01139da75cfc33", "prev": "1113f3a7c7ec83691ff5b8b20c7261fd32ba95174c9a45c38d0dd9f02e5cbd8e"} 2023-01-20T11:37:10.335Z INFO initializing dbft {"height": 91, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:10.336Z debug innerring/innerring.go:235 new block {"index": 90} 2023-01-20T11:37:10.370Z info neofs-node/main.go:114 notary service started successfully 2023-01-20T11:37:10.370Z info neofs-node/config.go:869 bootstrapping with online state {"previous": "OFFLINE"} 2023-01-20T11:37:10.376Z debug client/notary.go:522 notary request invoked {"method": "addPeer", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "500bb6b2c06a718c85c4b2ae5e601d3b905f6b49262812a84e460732f98d2076"} 2023-01-20T11:37:10.376Z info neofs-node/main.go:128 application started {"version": "v0.34.0"} 2023-01-20T11:37:10.377Z info neofs-node/main.go:110 starting control service... 2023-01-20T11:37:10.377Z info neofs-node/main.go:110 starting morph notification service... 2023-01-20T11:37:10.379Z info netmap/handlers.go:48 notification {"type": "add peer"} 2023-01-20T11:37:10.381Z info netmap/process_peers.go:65 approving network map candidate {"key": "022bb4041c50d607ff871dec7e4cd7778388e0ea6849d84ccbd9aa8f32e16a8131"} aio container started /usr/bin/neofs-rest-gw 2023-01-20T11:37:10.390Z debug client/notary.go:522 notary request invoked {"method": "addPeerIR", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "bed3e09c07461a0e5dfd07c3dd00f248ce6457acf067b362094c5aa61c108343"} 2023-01-20T11:37:10.410Z info neofs-http-gw/app.go:275 no wallet path specified, creating ephemeral key automatically for this run 2023-01-20T11:37:10.410Z info neofs-http-gw/app.go:158 add connection {"address": "localhost:8080", "weight": 1, "priority": 1} 2023-01-20T11:37:10.423Z debug session/executor.go:31 serving request... {"component": "SessionService", "request": "Create"} 2023-01-20T11:37:10.424Z warn neofs-http-gw/app.go:478 failed to reload TLS certs {"error": "tls disabled"} 2023-01-20T11:37:10.428Z warn neofs-http-gw/app.go:223 metrics are disabled 2023-01-20T11:37:10.430Z info neofs-http-gw/app.go:332 starting application {"app_name": "neofs-http-gw", "version": "v0.25.0"} 2023-01-20T11:37:10.430Z info neofs-http-gw/app.go:513 added path /upload/{cid} 2023-01-20T11:37:10.430Z info neofs-http-gw/app.go:516 added path /get/{cid}/{oid} 2023-01-20T11:37:10.430Z info neofs-http-gw/app.go:519 added path /get_by_attribute/{cid}/{attr_key}/{attr_val:*} 2023-01-20T11:37:10.431Z info neofs-http-gw/app.go:521 added path /zip/{cid}/{prefix} 2023-01-20T11:37:10.431Z info metrics/service.go:33 service hasn't started since it's disabled {"service": "Prometheus"} 2023-01-20T11:37:10.431Z info metrics/service.go:33 service hasn't started since it's disabled {"service": "Pprof"} 2023-01-20T11:37:10.431Z info neofs-http-gw/app.go:416 running web server {"address": "0.0.0.0:8081"} 2023-01-20T11:37:10.540Z INFO persisted to disk {"blocks": 1, "keys": 39, "headerHeight": 90, "blockHeight": 90, "took": "2.950447ms"} 2023-01-20T11:37:10.834Z info neofs-rest-gw/config.go:379 added connection peer {"address": "localhost:8080", "priority": 1, "weight": 1} 2023-01-20T11:37:10.845Z debug session/executor.go:31 serving request... {"component": "SessionService", "request": "Create"} 2023-01-20T11:37:10.914Z info metrics/service.go:33 service hasn't started since it's disabled {"service": "Pprof"} 2023-01-20T11:37:10.914Z info metrics/service.go:33 service hasn't started since it's disabled {"service": "Prometheus"} 2023/01/20 11:37:10 Serving neofs rest gw at http://[::]:8090 2023-01-20T11:37:11.335Z INFO sending PrepareRequest {"height": 91, "view": 0} 2023-01-20T11:37:11.336Z INFO sending Commit {"height": 91, "view": 0} 2023-01-20T11:37:11.336Z INFO approving block {"height": 91, "hash": "2928a5bfb2be7badcbced955ce221dc6da3ad4e75f42a0a5440b2d9beb93279b", "tx_count": 1, "merkle": "052f79c0eb9e889d1d396db5cc0beb8fca20b857376872880b7c77c84f934aba", "prev": "2d52b592230e3f65ebabc2eb38860d21dcd4d0e513f31445bbdafd3eb5d76ad4"} 2023-01-20T11:37:11.337Z INFO initializing dbft {"height": 92, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:11.338Z debug subscriber/subscriber.go:137 new notification event from sidechain {"name": "AddPeerSuccess"} 2023-01-20T11:37:11.338Z debug subscriber/subscriber.go:137 new notification event from sidechain {"name": "AddPeerSuccess"} 2023-01-20T11:37:11.338Z debug event/listener.go:326 event parser not set {"chain": "morph", "script hash LE": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event type": "AddPeerSuccess"} 2023-01-20T11:37:11.338Z debug neofs-node/morph.go:238 new block {"index": 91} 2023-01-20T11:37:11.338Z debug event/listener.go:326 event parser not set {"script hash LE": "0605a9623cb07b638fc6fe243bb7dc8bc50d30cd", "event type": "AddPeerSuccess"} 2023-01-20T11:37:11.339Z debug innerring/innerring.go:235 new block {"index": 91} 2023-01-20T11:37:11.542Z INFO persisted to disk {"blocks": 1, "keys": 37, "headerHeight": 91, "blockHeight": 91, "took": "2.739423ms"} 2023-01-20T11:37:12.342Z INFO sending PrepareRequest {"height": 92, "view": 0} 2023-01-20T11:37:12.342Z INFO sending Commit {"height": 92, "view": 0} 2023-01-20T11:37:12.343Z INFO approving block {"height": 92, "hash": "b9fbaa0e2e9263e93a637ed6e4c66be36131dd5b49b2ff5a721f7334ca5a7b2d", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "2928a5bfb2be7badcbced955ce221dc6da3ad4e75f42a0a5440b2d9beb93279b"} 2023-01-20T11:37:12.344Z INFO initializing dbft {"height": 93, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:12.344Z debug innerring/innerring.go:235 new block {"index": 92} 2023-01-20T11:37:12.345Z debug neofs-node/morph.go:238 new block {"index": 92} 2023-01-20T11:37:12.560Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 92, "blockHeight": 92, "took": "10.188473ms"} 2023-01-20T11:37:13.343Z INFO sending PrepareRequest {"height": 93, "view": 0} 2023-01-20T11:37:13.344Z INFO sending Commit {"height": 93, "view": 0} 2023-01-20T11:37:13.344Z INFO approving block {"height": 93, "hash": "f7d392481267289d427efe96b32170e1d90f1f5ab2e11152e2285baf116298d8", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "b9fbaa0e2e9263e93a637ed6e4c66be36131dd5b49b2ff5a721f7334ca5a7b2d"} 2023-01-20T11:37:13.346Z INFO initializing dbft {"height": 94, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:13.347Z debug neofs-node/morph.go:238 new block {"index": 93} 2023-01-20T11:37:13.347Z debug innerring/innerring.go:235 new block {"index": 93} 2023-01-20T11:37:13.567Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 93, "blockHeight": 93, "took": "9.687919ms"} 2023-01-20T11:37:14.344Z INFO sending PrepareRequest {"height": 94, "view": 0} 2023-01-20T11:37:14.345Z INFO sending Commit {"height": 94, "view": 0} 2023-01-20T11:37:14.345Z INFO approving block {"height": 94, "hash": "d4119119b023c665c04295dd114e0abf2756e66fd5d0d766ab893961eb866b2d", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "f7d392481267289d427efe96b32170e1d90f1f5ab2e11152e2285baf116298d8"} 2023-01-20T11:37:14.346Z INFO initializing dbft {"height": 95, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:14.347Z debug innerring/innerring.go:235 new block {"index": 94} 2023-01-20T11:37:14.347Z debug neofs-node/morph.go:238 new block {"index": 94} 2023-01-20T11:37:14.563Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 94, "blockHeight": 94, "took": "4.701267ms"} 2023-01-20T11:37:15.346Z INFO sending PrepareRequest {"height": 95, "view": 0} 2023-01-20T11:37:15.346Z INFO sending Commit {"height": 95, "view": 0} 2023-01-20T11:37:15.347Z INFO approving block {"height": 95, "hash": "122ade736ad6e42e1c7afb70c797ec703cf46cec8e4e2aefbf242d9c8618f200", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "d4119119b023c665c04295dd114e0abf2756e66fd5d0d766ab893961eb866b2d"} 2023-01-20T11:37:15.348Z INFO initializing dbft {"height": 96, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:15.348Z debug innerring/innerring.go:235 new block {"index": 95} 2023-01-20T11:37:15.349Z debug neofs-node/morph.go:238 new block {"index": 95} 2023-01-20T11:37:15.566Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 95, "blockHeight": 95, "took": "7.060374ms"} 2023-01-20T11:37:15.771Z INFO runtime log {"tx": "0e837b43226476d01d4cfaa0f2a2b59e17141a7ae9d67d462fc64270c4972624", "script": "f7a77b58e2581cb3f363977295ff870e42c42555", "msg": "successfully transferred assets"} 2023-01-20T11:37:15.772Z INFO runtime log {"tx": "0e837b43226476d01d4cfaa0f2a2b59e17141a7ae9d67d462fc64270c4972624", "script": "af4681232a16511654d007ee851a799a3475b551", "msg": "key bound to the owner"} 2023-01-20T11:37:15.772Z INFO runtime log {"tx": "0e837b43226476d01d4cfaa0f2a2b59e17141a7ae9d67d462fc64270c4972624", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "added new container"} 2023-01-20T11:37:15.785Z debug client/notary.go:522 notary request invoked {"method": "put", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "7e39e68f2041e951ee6767d4f71ef5ca93be0cc8d8a0a56106adefdf6653a1bf"} 2023-01-20T11:37:15.786Z info container/handlers.go:16 notification {"type": "container put", "id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"} 2023-01-20T11:37:15.797Z debug client/notary.go:404 notary request with prepared main TX invoked {"fallback_valid_for": 40, "tx_hash": "1b51ddc95049401ee9d3ce62790bd5d6f20b51f9a3aa4e821abf43bbe09d4336"} 2023-01-20T11:37:16.348Z INFO sending PrepareRequest {"height": 96, "view": 0} 2023-01-20T11:37:16.348Z INFO sending Commit {"height": 96, "view": 0} 2023-01-20T11:37:16.349Z INFO approving block {"height": 96, "hash": "91ea342cf82c017c72355a5967e46ba624aefdad84b0e675e8c43ccf85482f77", "tx_count": 1, "merkle": "7acaf73a141b9ae021190381c9d7e1df96ae1de3a45ef8d3d4cc3b7bbf0b3408", "prev": "122ade736ad6e42e1c7afb70c797ec703cf46cec8e4e2aefbf242d9c8618f200"} 2023-01-20T11:37:16.351Z INFO runtime log {"tx": "08340bbf7b3bccd4d3f85ea4e31dae96dfe1d7c981031921e09a1b143af7ca7a", "script": "f7a77b58e2581cb3f363977295ff870e42c42555", "msg": "successfully transferred assets"} 2023-01-20T11:37:16.352Z INFO runtime log {"tx": "08340bbf7b3bccd4d3f85ea4e31dae96dfe1d7c981031921e09a1b143af7ca7a", "script": "af4681232a16511654d007ee851a799a3475b551", "msg": "key bound to the owner"} 2023-01-20T11:37:16.352Z INFO runtime log {"tx": "08340bbf7b3bccd4d3f85ea4e31dae96dfe1d7c981031921e09a1b143af7ca7a", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "added new container"} 2023-01-20T11:37:16.353Z INFO initializing dbft {"height": 97, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:16.355Z debug subscriber/subscriber.go:137 new notification event from sidechain {"name": "PutSuccess"} 2023-01-20T11:37:16.355Z debug neofs-node/morph.go:238 new block {"index": 96} 2023-01-20T11:37:16.355Z error neofs-node/container.go:92 read newly created container after the notification {"id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P", "error": "status: code = 3072"} 2023-01-20T11:37:16.356Z debug neofs-node/container.go:98 container creation event's receipt {"id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"} 2023-01-20T11:37:16.357Z debug subscriber/subscriber.go:137 new notification event from sidechain {"name": "Transfer"} 2023-01-20T11:37:16.358Z debug event/listener.go:326 event parser not set {"chain": "morph", "script hash LE": "f7a77b58e2581cb3f363977295ff870e42c42555", "event type": "Transfer"} 2023-01-20T11:37:16.359Z debug subscriber/subscriber.go:137 new notification event from sidechain {"name": "TransferX"} 2023-01-20T11:37:16.359Z debug event/listener.go:326 event parser not set {"chain": "morph", "script hash LE": "f7a77b58e2581cb3f363977295ff870e42c42555", "event type": "TransferX"} 2023-01-20T11:37:16.360Z debug innerring/innerring.go:235 new block {"index": 96} 2023-01-20T11:37:16.361Z debug event/listener.go:394 notary parser not set {"chain": "morph", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "method": "put"} 2023-01-20T11:37:16.566Z INFO persisted to disk {"blocks": 1, "keys": 49, "headerHeight": 96, "blockHeight": 96, "took": "5.623832ms"} 2023-01-20T11:37:17.000Z debug session/executor.go:31 serving request... {"component": "SessionService", "request": "Create"} 2023-01-20T11:37:17.035Z INFO runtime log {"tx": "cc3d1bf533286df96c82f7981b8b19ab2670cd92366a98493835e127645798cd", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "remove container"} 2023-01-20T11:37:17.044Z debug client/notary.go:522 notary request invoked {"method": "delete", "valid_until_block": 200, "fallback_valid_for": 40, "tx_hash": "1b016d77ada85fd9e5b35d0ddd9c98947145d54e815c12665952a5adaae60e92"} 2023-01-20T11:37:17.047Z info container/handlers.go:32 notification {"type": "container delete", "id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"} 2023-01-20T11:37:17.055Z debug client/notary.go:404 notary request with prepared main TX invoked {"fallback_valid_for": 40, "tx_hash": "567f3cbb420a958272b2f01950988e8c0bf07685923ee376a34e6154d361812b"} 2023-01-20T11:37:17.350Z INFO sending PrepareRequest {"height": 97, "view": 0} 2023-01-20T11:37:17.350Z INFO sending Commit {"height": 97, "view": 0} 2023-01-20T11:37:17.352Z INFO approving block {"height": 97, "hash": "eefa343ae235c75d9e528bf1c5e5a957a313c1f4c10a00f7f8a7271e9bffe3e6", "tx_count": 1, "merkle": "ce1282a8af2dd7e3184e8f9602f2cb1846d35db752c1ae1a3374746a78690715", "prev": "91ea342cf82c017c72355a5967e46ba624aefdad84b0e675e8c43ccf85482f77"} 2023-01-20T11:37:17.352Z INFO runtime log {"tx": "150769786a7474331aaec152b75dd34618cbf202968f4e18e3d72dafa88212ce", "script": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "msg": "remove container"} 2023-01-20T11:37:17.353Z INFO initializing dbft {"height": 98, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:17.355Z debug innerring/innerring.go:235 new block {"index": 97} 2023-01-20T11:37:17.355Z debug event/listener.go:394 notary parser not set {"chain": "morph", "contract": "4fe02bcf074db1b6a5b71c13e3ac04e4bcfc3a96", "method": "delete"} 2023-01-20T11:37:17.356Z debug subscriber/subscriber.go:137 new notification event from sidechain {"name": "DeleteSuccess"} 2023-01-20T11:37:17.356Z debug neofs-node/container.go:117 container removal event's receipt {"id": "2sp9MAJAmJNxS9cYoz7fuq2juDA46Y4JaHF9fXTEkQ8P"} 2023-01-20T11:37:17.357Z debug neofs-node/morph.go:238 new block {"index": 97} 2023-01-20T11:37:17.565Z INFO persisted to disk {"blocks": 1, "keys": 31, "headerHeight": 97, "blockHeight": 97, "took": "3.769574ms"} 2023-01-20T11:37:18.353Z INFO sending PrepareRequest {"height": 98, "view": 0} 2023-01-20T11:37:18.353Z INFO sending Commit {"height": 98, "view": 0} 2023-01-20T11:37:18.353Z INFO approving block {"height": 98, "hash": "5167f23a92c2f21b4e3e6fed3eeda8732e10ac8b06cd1a35fbe5150c26749991", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "eefa343ae235c75d9e528bf1c5e5a957a313c1f4c10a00f7f8a7271e9bffe3e6"} 2023-01-20T11:37:18.354Z INFO initializing dbft {"height": 99, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:18.354Z debug innerring/innerring.go:235 new block {"index": 98} 2023-01-20T11:37:18.355Z debug neofs-node/morph.go:238 new block {"index": 98} 2023-01-20T11:37:18.565Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 98, "blockHeight": 98, "took": "2.542078ms"} 2023-01-20T11:37:19.354Z INFO sending PrepareRequest {"height": 99, "view": 0} 2023-01-20T11:37:19.355Z INFO sending Commit {"height": 99, "view": 0} 2023-01-20T11:37:19.356Z INFO approving block {"height": 99, "hash": "cea57969c015af4d77f18f44aaa474b0e82ec7b93fcaa8d26f03441d626e4efa", "tx_count": 0, "merkle": "0000000000000000000000000000000000000000000000000000000000000000", "prev": "5167f23a92c2f21b4e3e6fed3eeda8732e10ac8b06cd1a35fbe5150c26749991"} 2023-01-20T11:37:19.357Z INFO initializing dbft {"height": 100, "view": 0, "index": 0, "role": "Primary"} 2023-01-20T11:37:19.358Z debug innerring/innerring.go:235 new block {"index": 99} 2023-01-20T11:37:19.359Z debug neofs-node/morph.go:238 new block {"index": 99} 2023-01-20T11:37:19.567Z INFO persisted to disk {"blocks": 1, "keys": 20, "headerHeight": 99, "blockHeight": 99, "took": "4.489724ms"} 2023-01-20T11:37:20.357Z INFO sending PrepareRequest {"height": 100, "view": 0} 2023-01-20T11:37:20.358Z INFO sending Commit {"height": 100, "view": 0} ``` @roman-khimov
sami 2025-12-28 18:11:11 +00:00
  • closed this issue
  • added the
    bug
    label
Author
Owner

@roman-khimov commented on GitHub (Jan 23, 2023):

Seems to be a node issue to me, but let's have it there for now.

@roman-khimov commented on GitHub (Jan 23, 2023): Seems to be a node issue to me, but let's have it there for now.
Author
Owner

@roman-khimov commented on GitHub (Jan 23, 2023):

In fact, this looks a lot like nspcc-dev/neofs-node#2155 and may be fixed by nspcc-dev/neofs-node#2176.

@roman-khimov commented on GitHub (Jan 23, 2023): In fact, this looks a lot like nspcc-dev/neofs-node#2155 and may be fixed by nspcc-dev/neofs-node#2176.
Author
Owner

@roman-khimov commented on GitHub (Apr 17, 2023):

Please retry now with new NeoFS node (after #50).

@roman-khimov commented on GitHub (Apr 17, 2023): Please retry now with new NeoFS node (after #50).
Author
Owner

@mialbu commented on GitHub (Apr 18, 2023):

Please retry now with new NeoFS node (after #50).

Hey @roman-khimov I've just tried to use neofs-aio on the latest commit, but I can't start the container. It works with commit 74b925abde where you changed the docker-compose to just use one image, but I run into the following error with commit da7afa705e:

image

I get the same error when using the latest commit (f6c31d6c33).

I've cleared the local cache as mentioned in the README but that did not help.

@mialbu commented on GitHub (Apr 18, 2023): > Please retry now with new NeoFS node (after #50). Hey @roman-khimov I've just tried to use neofs-aio on the latest commit, but I can't start the container. It works with commit 74b925abde8a96ea22882d73b1ad797d30d7d5fb where you changed the docker-compose to just use one image, but I run into the following error with commit da7afa705e4ab4351061a663eeceda631b8aad70: ![image](https://user-images.githubusercontent.com/53603111/232847414-c104e706-fbf3-46dd-b8d5-16b1f1ff0740.png) I get the same error when using the latest commit (f6c31d6c33917817d2741356efb1a0462d824608). I've cleared the local cache as mentioned in the README but that did not help.
Author
Owner

@roman-khimov commented on GitHub (Apr 18, 2023):

Ah, it's just missing from the Docker Hub. If you're to make it first, it'll be OK, but let's upload it to the Hub as well...

@roman-khimov commented on GitHub (Apr 18, 2023): Ah, it's just missing from the Docker Hub. If you're to `make` it first, it'll be OK, but let's upload it to the Hub as well...
Author
Owner
@roman-khimov commented on GitHub (Apr 18, 2023): Should be OK now either way: https://hub.docker.com/layers/nspccdev/neofs-aio/0.36.0/images/sha256-4cd2fef8eda536daa5525508dfde2888ff730d68dc89ff90cc20765c77dd3750?context=explore
Author
Owner

@roman-khimov commented on GitHub (Jun 21, 2023):

We've got 0.37.0 version now, please check.

@roman-khimov commented on GitHub (Jun 21, 2023): We've got 0.37.0 version now, please check.
Author
Owner

@mialbu commented on GitHub (Jun 22, 2023):

We've got 0.37.0 version now, please check.

Hey @roman-khimov, it works with 0.37.0, awesome! Sorry for the late response.

@mialbu commented on GitHub (Jun 22, 2023): > We've got 0.37.0 version now, please check. Hey @roman-khimov, it works with 0.37.0, awesome! Sorry for the late response.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
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
nspcc-dev/neofs-aio#17
No description provided.