vegaprotocol / vega

A Go implementation of the Vega Protocol, a protocol for creating and trading derivatives on a fully decentralised network.
https://vega.xyz
GNU Affero General Public License v3.0
37 stars 22 forks source link

panic similar to #6373 #6374

Closed fkondej closed 2 years ago

fkondej commented 2 years ago

Problem encountered

Validator panic'ed during restart, the stack trace is similar to #6373

Observed behaviour

n01.devnet1.vega.xys - is a validator server with vegavaisor. Every 30 min a random server is restarted, this single restart failed.

Expected behaviour

The server should restart.

Evidence

Logs

Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.416Z        INFO        validators        validators/validator_set.go:145        setting voting power to        {"address": "4D9FC26A72A6F94D844E8B0785AE4803BB2672C6", "power": 2517}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.416Z        INFO        validators        validators/validator_set.go:145        setting voting power to        {"address": "930F4525243DC942E3A0655E23442A902C04814E", "power": 2505}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.416Z        INFO        rewards.rewards        rewards/engine.go:255        tendermint/ersatz fractions of the reward        {"total-delegation": "12000000000000000000000", "tenderming-total-delegation": "12000000000000000000000", "ersatz-total-delegation": "0", "tenderming-factor": "1", "ersatz-factor": "0"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.416Z        INFO        rewards.rewards        rewards/engine.go:278        Rewards: calculated normalised score for tendermint validators        {"validator": "927cbf8d5909cc017cf78ea9806fd57c3115d37e481eaf9d866f526b356f3ced", "normalisedScore": "0.251702209409718"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.416Z        INFO        rewards.rewards        rewards/engine.go:278        Rewards: calculated normalised score for tendermint validators        {"validator": "95893347980299679883f817f118718f949826d1a0a1c2e4f22ba5f0cd6d1f5d", "normalisedScore": "0.2505279096640252"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.417Z        INFO        rewards.rewards        rewards/engine.go:278        Rewards: calculated normalised score for tendermint validators        {"validator": "15e41e63820f0dfaaaf44cf6d73f4d598e4769432d84c4ddd7e95289508d6519", "normalisedScore": "0.2505279096640252"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.417Z        INFO        rewards.rewards        rewards/engine.go:278        Rewards: calculated normalised score for tendermint validators        {"validator": "4554375ce61b6828c6f7b625b7735034496b7ea19951509cccf4eb2ba35011b0", "normalisedScore": "0.2472419712622316"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.417Z        INFO        spam        spam/engine.go:167        Spam protection OnEpochEvent called        {"epoch": 11}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.417Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "03d6f465fea5242dea203a2a6e4477cebbbd308d461be1586ae06f38af56f79a", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.417Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "10d3d4a03a16bc67f811099934bcf1aeaf1f220cd37341e976a8974352353408", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.417Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "1647e6a86bfc898050e7167eb88307e0941ba8829a48456370daf0b02142a53c", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "173d3c8712954c1e1e2505baf38a27056eb6176bf7b4a8c054a45ba6781dda0d", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "1f4569d999e3f9feee8e06175475f37f6ac67dd3aa205b91bf938176ef3b0621", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "23dc2fde297fcea3058578c4c4174795192f0057fd7d181016696c37ed86508f", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "35edee192a4b49a50a11bb0d7964dad8de0dd4885ac87e1c3251bd236836f1fd", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "36b252f1ab92d7316a032f17c2ab35bd4cb0e2f7c9dcbef8174654b43248c8be", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "3c74345c935b5e95dc60dcbc355d69591c405e625729eedc9538dfdc64e3772e", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "3f498ac2858cd93f779d685b28fb724855ca5df484a69a1f2ce6224251d7ba8f", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.418Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "425efc2a7099db6c308aef90d51162c0cdddbd8c6429ca11df786252a7e3a2b8", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "5780787f1de97db7ddb47cc4f7e92f21a3ca13e4d8cf461b06cff02fd3d84763", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "6a6e8474ae6a1594b02c7e60bb4655be633ee0970eb638acc0f59e8b995ce255", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "70a8e768923a93809a0c2a0acf573f48f8ae30b911e6f9027663a5b8f9d70ca4", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "71d377789b3731e8780faa6dd5e01311ae140f60a48896d341c8727d61c1d038", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "77ee84b8fe2c516711d44592f3561a6053e7ba095b9fd55370c77d2c832bd51b", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "89b11a1f57835cf5db38c9ae27f5238feb20091be24e159d2e76dda5ef62be6b", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "89ddfe4ffa26ce374579ebf3cef754cee20dcfd1cb7a9bf6c839bb95bc93e4b3", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.419Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "ad3a7c8f8ae3809dc1242fdbae5f20da6bc1e28eb36b7feffaa817d53efd2631", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.420Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "bc9a0c675a5950c351cda476e087935ef541f0002cb2324a2f66dc71dd3c61b6", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.420Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "c9b5a49b9a1c25571f3e36437adfef60e30ef66093c9ce17bea4d92282200896", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.420Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "cee1a871ce81b38e1ff55d1564b41c6554dc24cf4e7546f673d4c1f8b55736d3", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.420Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "e7efac3e8083eac4e3cc9401a89418af29e6fdc3dcf15b2d2cdd07d89db5a796", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.420Z        ERROR        validators        validators/witness.go:394        could not send command        {"res-id": "fa52c1c5b52612237cc9e57e73b2e8b082b5d61258b03977eaeef51b875a7cf7", "error": "no self votes received after 10 seconds"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.420Z        INFO        execution        execution/auction.go:82        leaving opening auction for market        {"market-id": "966defe7b067a489a55502f7648ce787619dbe954ae6339d866cbb9227c7dd14"}
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.421Z        INFO        root        protocol/protocol.go:143        Stopping protocol services
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.421Z        INFO        event-forwarder        evtforward/engine.go:145        Stopping the Ethereum Event Forwarder
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.421Z        INFO        event-forwarder        evtforward/engine.go:148        The Event Forwarder engine stopped
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.421Z        INFO        api.grpc        api/grpc.go:273        Gracefully stopping gRPC based API
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.422Z        INFO        api.restproxy        rest/server.go:132        Stopping REST<>GRPC based API
Oct 01 22:28:01 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:01.422Z        INFO        admin.server        admin/server.go:152        Stopping Server<>RPC based API
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:02.534Z        INFO        pprof        pprof/pprof.go:148        saving pprof memory profile        {"path": "/home/vega/pprof/vega/pprof/mem-2022-10-01-22-27-55.pprof"}
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:02.534Z        INFO        pprof        pprof/pprof.go:149        saving pprof cpu profile        {"path": "/home/vega/pprof/vega/pprof/cpu-2022-10-01-22-27-55.pprof"}
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: 2022-10-01T22:28:02.722Z        INFO        root        node/node.go:253        Vega shutdown complete        {"version": "v0.58.0+dev-10437-435928678", "version-hash": "43592867815fddda2fb3e951e909b78fc51e92c0-modified"}
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: panic: runtime error: invalid memory address or nil pointer dereference [recovered]
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         panic: runtime error: invalid memory address or nil pointer dereference
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x11a122e]
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: goroutine 139 [running]:
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/cmd/vega/node.(*Command).Run.func1.1()
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/cmd/vega/node/node.go:141 +0x59
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: panic({0x21087a0, 0x3abf120})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /usr/local/go/src/runtime/panic.go:884 +0x212
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/metrics.(*TimeCounter).EngineTimeCounterAdd(0x0)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/metrics/timecounter.go:49 +0x2e
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/monitor.(*AuctionState).Left(0xc014b7fef0, {0x2a1bc30, 0xc014cf6180}, {0xc014cf8b00?, 0xc014c37e20?, 0x0?})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/monitor/auction.go:267 +0x65
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/execution.(*Market).leaveAuction(0xc013fae3c0, {0x2a1bc30, 0xc014cf6180}, {0xc014cf8a40?, 0x1?, 0x0?})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/execution/market.go:1053 +0xacf
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/execution.(*Market).checkAuction(0xc013fae3c0, {0x2a1bc30, 0xc014cf6180}, {0x641df54?, 0xedacab3b6?, 0x0?})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/execution/auction.go:83 +0x629
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/execution.(*Market).OnTick(0xc013fae3c0, {0x2a1bc30, 0xc014cf6180}, {0x0?, 0x0?, 0x0?})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/execution/market.go:723 +0x8ec
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/execution.(*Engine).OnTick(0xc000103040, {0x2a1bc30, 0xc014cf6180}, {0x1?, 0x2a29360?, 0x0?})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/execution/engine.go:756 +0x253
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/vegatime.(*Svc).notify(...)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/vegatime/service.go:104
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/vegatime.(*Svc).SetTimeNow(0xc000ea4580, {0x2a1bc30, 0xc014cf6180}, {0x40?, 0x2021340?, 0x0?})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/vegatime/service.go:77 +0x24f
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/processor.(*App).OnBeginBlock(_, {{0xc014cfa3a0, 0x20, 0x20}, {{0xb, 0x1}, {0xc014cd41c0, 0x19}, 0x385, {0xf6ad6b4, ...}, ...}, ...})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/processor/abci.go:724 +0x730
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/blockchain/abci.(*App).BeginBlock(_, {{0xc014cfa3a0, 0x20, 0x20}, {{0xb, 0x1}, {0xc014cd41c0, 0x19}, 0x385, {0xf6ad6b4, ...}, ...}, ...})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/blockchain/abci/abci.go:46 +0x75
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/cmd/vega/node.(*appW).BeginBlock(_, {{0xc014cfa3a0, 0x20, 0x20}, {{0xb, 0x1}, {0xc014cd41c0, 0x19}, 0x385, {0xf6ad6b4, ...}, ...}, ...})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/cmd/vega/node/app_wrapper.go:68 +0x55
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/abci/client.(*localClient).BeginBlockSync(_, {{0xc014cfa3a0, 0x20, 0x20}, {{0xb, 0x1}, {0xc014cd41c0, 0x19}, 0x385, {0xf6ad6b4, ...}, ...}, ...})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/abci/client/local_client.go:280 +0x118
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/proxy.(*appConnConsensus).BeginBlockSync(_, {{0xc014cfa3a0, 0x20, 0x20}, {{0xb, 0x1}, {0xc014cd41c0, 0x19}, 0x385, {0xf6ad6b4, ...}, ...}, ...})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/proxy/app_conn.go:81 +0x55
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/state.execBlockOnProxyApp({0x2a1a4c8?, 0xc000014768}, {0x2a25cc0, 0xc000f93cd0}, 0xc013faef00, {0x2a2e838, 0xc00117d200}, 0xc014c30b60?)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/state/execution.go:307 +0x3dd
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/state.ExecCommitBlock({0x2a25cc0, 0xc000f93cd0}, 0xc013faef00, {0x2a1a4c8, 0xc000014768}, {0x2a2e838?, 0xc00117d200?}, 0x400?)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/state/execution.go:537 +0x67
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/consensus.(*Handshaker).replayBlocks(_, {{{0xb, 0x1}, {0xc0010d9e00, 0x7}}, {0xc0122d9260, 0x19}, 0x1, 0x4ac, {{0xc0122d9280, ...}, ...}, ...}, ...)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/consensus/replay.go:471 +0x248
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/consensus.(*Handshaker).ReplayBlocks(_, {{{0xb, 0x1}, {0xc0010d9e00, 0x7}}, {0xc0122d9260, 0x19}, 0x1, 0x4ac, {{0xc0122d9280, ...}, ...}, ...}, ...)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/consensus/replay.go:393 +0x479
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/consensus.(*Handshaker).Handshake(0xc011a12e18, {0x2a31170, 0xc00014cc30})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/consensus/replay.go:268 +0x3d4
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/node.doHandshake({_, _}, {{{0xb, 0x1}, {0xc0010d9e00, 0x7}}, {0xc0122d9260, 0x19}, 0x1, 0x4ac, ...}, ...)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/node/node.go:330 +0x1b8
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: github.com/tendermint/tendermint/node.NewNode(0xc0001f2280, {0x2a15c80, 0xc000e377c0}, 0xc000f217d0, {0x2a059c0, 0xc00117ca20}, 0x0?, 0xc0011adb50?, 0xc000f21850, {0x2a1a4c8, ...}, ...)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/GOPATH/pkg/mod/github.com/tendermint/tendermint@v0.34.21/node/node.go:778 +0x597
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/core/blockchain/abci.NewTmNode({{0x0}, 0x1, 0x1, 0x0, 0x0, {0xc0001359b0, 0xa}, {{0x0}, {0xc000f23230, 0x15}}, ...}, ...)
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/core/blockchain/abci/tm_node.go:78 +0x6a5
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/cmd/vega/node.(*Command).startABCI(0xc0010d5000, {0x2a2ed40, 0xc0010ba380}, {0x7ffc9f745e6f, 0x1a}, {0x0?, 0x0?}, {0x0?, 0x0?})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/cmd/vega/node/node.go:442 +0x189
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/cmd/vega/node.(*Command).startBlockchain(0xc0010d5000, {0x7ffc9f745e6f?, 0xc0010e3830?}, {0x0, 0x0}, {0x0, 0x0})
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/cmd/vega/node/node.go:333 +0x37b
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: code.vegaprotocol.io/vega/cmd/vega/node.(*Command).Run.func1()
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/cmd/vega/node/node.go:144 +0x7e
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]: created by code.vegaprotocol.io/vega/cmd/vega/node.(*Command).Run
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735274]:         /jenkins/workspace/private/Deployments/Publish-vega-dev-releases/vega/cmd/vega/node/node.go:135 +0x645
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735248]: 2022-10-01T22:28:02.765Z        ERROR        root        visor/visor.go:131        Binaries executions has failed        {"error": "failed to execute binary /home/vega/vegavisor_home/current/vega [start --home /home/vega/vega_home --tendermint-home /home/vega/tendermint_home --nodewallet-passphrase-file /home/vega/vega_home/all-wallet-passphrase.txt --snapshot.load-from-block-height -1]: exit status 2"}
Oct 01 22:28:02 n01.devnet1.vega.xyz visor[735248]: 2022-10-01T22:28:02.768Z        INFO        root        visor/visor.go:138        Binaries restart is scheduled        {"restartDelay": "5s"}

Additional context

Devnet 1 network:

Definition of Done

ℹ️ Not every issue will need every item checked, however, every item on this list should be properly considered and actioned to meet the DoD.

Before Merging

After Merging

jeremyletang commented 2 years ago

This is a segv because of prometheus metrics. Are we using the “Auction duration” metrics at all? It not removing it will fix this.

fkondej commented 2 years ago

yes, we have metrics enabled: https://github.com/vegaprotocol/ansible/blob/master/roles/barenode/templates/vega/config.toml.j2#L122-L127

[Metrics]
  Level = "Info"
  Timeout = "5s"
  Port = 2112
  Path = "/metrics"
  Enabled = true
jeremyletang commented 2 years ago

What I meant was do we have any utility for this specific metric I mentioned. The issue is that we don’t restart the time counter over a snapshot restart, which panic when trying to use the pointer