Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Cannot create object right after container start up #47

Closed
mialbu opened this issue Jan 23, 2023 · 8 comments
Closed

Cannot create object right after container start up #47

mialbu opened this issue Jan 23, 2023 · 8 comments
Labels
bug Something isn't working

Comments

@mialbu
Copy link

mialbu commented Jan 23, 2023

With the latest to provide neofs-aio in one single image (commit 74b925a) 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 (fd04125).

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
@roman-khimov roman-khimov added the bug Something isn't working label Jan 23, 2023
@roman-khimov
Copy link
Member

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

@roman-khimov
Copy link
Member

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

@roman-khimov
Copy link
Member

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

@mialbu
Copy link
Author

mialbu commented Apr 18, 2023 •
edited
Loading

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 74b925a where you changed the docker-compose to just use one image, but I run into the following error with commit da7afa7:

image

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

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

@roman-khimov
Copy link
Member

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
Copy link
Member

Should be OK now either way: https://hub.docker.com/layers/nspccdev/neofs-aio/0.36.0/images/sha256-4cd2fef8eda536daa5525508dfde2888ff730d68dc89ff90cc20765c77dd3750?context=explore

@roman-khimov
Copy link
Member

We've got 0.37.0 version now, please check.

@mialbu
Copy link
Author

mialbu commented 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 mialbu closed this as completed Jun 22, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@roman-khimov @mialbu