search

ava-labs / avalanchego

Go implementation of an Avalanche node.
https://avax.network
BSD 3-Clause "New" or "Revised" License
2.13k stars 672 forks source link

Can not make X-Chain calls after <X Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166 #311

Closed otherpaco closed 4 years ago

otherpaco commented 4 years ago

Describe the bug When I make API-calls to the X-Chain I don't get any response.

Calls to health, P-Chain... are working.

To Reproduce

Expected behavior get a response

Screenshots If applicable, add screenshots to help explain your problem.

Operating System Ubuntu 20.04. 64 bit on ARM Raspi4 8GB plus 16GB swap gecko 0.5.7 build from source

Additional context I tried to rebuild gecko 0.5.7 I tried 0.5.5 I tried master

It was working before.

I stopped gecko, removed the db folder, started gecko, imported user and accounts

all of the above was not working

I will add logs here. There you can see the following: before " /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166" I can make X-Chain API-Calls. After that line I can make calls to other endpoints. When I make a call after that line to the X-Chain I dont get any response. I stopped gecko with ctrl+c

WARN [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/main/main.go#74: NAT traversal has failed. The node will be able to connect to less nodes.
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/node/node.go#545: Gecko version is: avalanche/0.5.7
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/node/node.go#281: Set node's ID to E9cBEoCDBGi6qFGcW6bfFoyhWpq6Vc57Q
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/node/node.go#394: Initializing API server
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/node/node.go#447: initializing Keystore API
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/keystore
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/node/node.go#459: initializing Metrics API
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/api/server.go#53: API server listening on "127.0.0.1:9650"
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/metrics
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/node/node.go#439: initializing SharedMemory
INFO [08-10|16:50:11] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/jvYyfQTxGMJLuGWa55kdP2p2zSUYsQ5Raupu4TW34ZAUBAbtq
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/sqjdyTKUSrQs1YmKDTUbdUhdstSdtRTGRbUn8sqK8B6pkZkz1
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/sqjchUjzDqDfBPGjfQq2tXW1UCwZTyvzAWHsNzF2cb1eVHt6w
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/node/node.go#479: initializing Info API
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/info
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/node/node.go#492: initializing Health API
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/health
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/node/node.go#510: initializing aliases
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/node/node.go#338: initializing chains
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/rWhpuQPF1kb72esV2momhMuTYGkEb1oL29pt2EBXWmSy4kxnT
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: 11111111111111111111111111111111LpoYY
    VMID:rWhpuQPF1kb72esV2momhMuTYGkEb1oL29pt2EBXWmSy4kxnT
INFO [08-10|16:50:12] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/vm.go#363: initializing Subnets
INFO [08-10|16:50:12] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/vm.go#349: initializing blockchains
INFO [08-10|16:50:12] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/vm.go#327: Initializing last accepted block as 2gha7M3ebHr1Nm9tuz9rKXVsEpstqkcViFLhJmAdqUshY416W8
INFO [08-10|16:50:12] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/11111111111111111111111111111111LpoYY
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:50:12] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:50:13] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [08-10|16:50:13] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:50:13] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:50:13] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with 2gha7M3ebHr1Nm9tuz9rKXVsEpstqkcViFLhJmAdqUshY416W8 as the last accepted block
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: rrEWX7gc7D9mwcdrdBxBTdqh1a7WDVsMuadhTZgyXfFcRz45L
    VMID:jvYyfQTxGMJLuGWa55kdP2p2zSUYsQ5Raupu4TW34ZAUBAbtq
INFO [08-10|16:50:13] <X Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#54: Initializing consensus engine
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/rrEWX7gc7D9mwcdrdBxBTdqh1a7WDVsMuadhTZgyXfFcRz45L
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/rrEWX7gc7D9mwcdrdBxBTdqh1a7WDVsMuadhTZgyXfFcRz45L/pubsub
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: zJytnh96Pc8rM337bBrtMvJDbEdDNjcXG3WkTNCiLp18ergm9
    VMID:mgj786NP7uDwBCcq6YwThhaN8FLyybkCa4zBWTQbNgmK6k9A6
INFO [08-10|16:50:13] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/zJytnh96Pc8rM337bBrtMvJDbEdDNjcXG3WkTNCiLp18ergm9/rpc
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/zJytnh96Pc8rM337bBrtMvJDbEdDNjcXG3WkTNCiLp18ergm9/ws
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: 1GHaaPbg1YBR4qiATuFNfL2j9StJwmddwXiwm1s9ts5KXvMai
    VMID:sqjdyTKUSrQs1YmKDTUbdUhdstSdtRTGRbUn8sqK8B6pkZkz1
INFO [08-10|16:50:13] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#54: Initializing consensus engine
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/1GHaaPbg1YBR4qiATuFNfL2j9StJwmddwXiwm1s9ts5KXvMai
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: jV7eZZh6Y2a35aaMLUGwBN1g2PNqfuuxLTSHu98EpHyPJDcQJ
    VMID:sqjchUjzDqDfBPGjfQq2tXW1UCwZTyvzAWHsNzF2cb1eVHt6w
INFO [08-10|16:50:13] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/jV7eZZh6Y2a35aaMLUGwBN1g2PNqfuuxLTSHu98EpHyPJDcQJ
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: am6cZ3MqzsbJG5mhNvrX2Z3w5uzRxZtgEacwhNqQ5p5KHAhtM
    VMID:tGas3T58KzdjLHhBDMnH2TvrddhqTji5iZAMZ3RXs2NLpSnhH
INFO [08-10|16:50:13] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:50:13] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/am6cZ3MqzsbJG5mhNvrX2Z3w5uzRxZtgEacwhNqQ5p5KHAhtM
INFO [08-10|16:50:14] /go/src/github.com/ava-labs/gecko/api/health/service.go#90: Health: GetLiveness called
INFO [08-10|16:50:16] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/service.go#301: Platform: GetPendingValidators called
INFO [08-10|16:50:19] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#82: AVM: GetTxStatus called with 2gZTNyRV7DdALck9mukgU8DZz4v9Gu8cvdfXNzP8oLbjgghkQU
INFO [08-10|16:50:20] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#82: AVM: GetTxStatus called with 2gZTNyRV7DdALck9mukgU8DZz4v9Gu8cvdfXNzP8oLbjgghkQU
INFO [08-10|16:50:21] <X Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 135 vertices in the accepted frontier
INFO [08-10|16:50:21] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#164: Bootstrapping finished with no accepted frontier. This is likely a result of failing to be able to connect to the specified bootstraps, or no transactions have been issued on this chain yet
INFO [08-10|16:50:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#164: Bootstrapping finished with no accepted frontier. This is likely a result of failing to be able to connect to the specified bootstraps, or no transactions have been issued on this chain yet
INFO [08-10|16:50:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#292: finished fetching 0 vertices. executing transaction state transitions...
INFO [08-10|16:50:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#333: executed 0 operations
INFO [08-10|16:50:21] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:50:21] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:50:21] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [08-10|16:50:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#298: executing vertex state transitions...
INFO [08-10|16:50:21] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:50:21] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:50:21] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with HQDeiNXCxDmETYpd7uRrnoKSeh71kS5cphKibCJMN6G1DmUFH as the last accepted block
INFO [08-10|16:50:21] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [08-10|16:50:21] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:50:21] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:50:21] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with JJoWekhXrFYrcbw6t1wqC37vXT1QWUBskRyGskzBM6Q1sN8XJ as the last accepted block
INFO [08-10|16:50:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#333: executed 0 operations
INFO [08-10|16:50:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#84: bootstrapping finished with 0 vertices in the accepted frontier
INFO [08-10|16:50:21] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with BhdXsMYpJsjGdgk1wqUWcukurCovwv9hpKMuLv7bJ9jVeSZJj as the last accepted block
INFO [08-10|16:50:28] /go/src/github.com/ava-labs/gecko/api/health/service.go#90: Health: GetLiveness called
INFO [08-10|16:50:32] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/service.go#237: Platform: GetCurrentValidators called
INFO [08-10|16:50:36] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/service.go#440: Platform: ListAccounts called for user 'paco'
^CINFO [08-10|16:50:41] /go/src/github.com/ava-labs/gecko/node/node.go#595: shutting down the node
INFO [08-10|16:50:41] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:50:41] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:50:41] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:50:41] <P Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:50:41] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#111: shutting down consensus engine
INFO [08-10|16:50:41] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:50:41] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:50:41] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:50:41] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:50:41] <C Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
WARN [08-10|16:50:42] /go/src/github.com/ava-labs/gecko/snow/networking/router/chain_router.go#349: timed out while shutting down the chains
INFO [08-10|16:50:42] /go/src/github.com/ava-labs/gecko/node/node.go#599: node shut down successfully
INFO [08-10|16:50:42] /go/src/github.com/ava-labs/gecko/nat/nat.go#138: Unmapped all ports
FATAL[08-10|16:50:42] <X Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#185: forcing chain to shutdown due to closed
INFO [08-10|16:50:42] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#82: AVM: GetTxStatus called with 2gZTNyRV7DdALck9mukgU8DZz4v9Gu8cvdfXNzP8oLbjgghkQU
INFO [08-10|16:50:42] <X Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain

Sometimes I get a different message on stopping. Here I made a getBalance call. I always get one of the two FATALs, I did not find a way to say when I get the first or second case.

WARN [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/main/main.go#74: NAT traversal has failed. The node will be able to connect to less nodes.
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#545: Gecko version is: avalanche/0.5.7
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#281: Set node's ID to E9cBEoCDBGi6qFGcW6bfFoyhWpq6Vc57Q
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#394: Initializing API server
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#447: initializing Keystore API
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/keystore
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#53: API server listening on "127.0.0.1:9650"
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#459: initializing Metrics API
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/metrics
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#439: initializing SharedMemory
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/jvYyfQTxGMJLuGWa55kdP2p2zSUYsQ5Raupu4TW34ZAUBAbtq
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/sqjdyTKUSrQs1YmKDTUbdUhdstSdtRTGRbUn8sqK8B6pkZkz1
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/sqjchUjzDqDfBPGjfQq2tXW1UCwZTyvzAWHsNzF2cb1eVHt6w
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#479: initializing Info API
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/info
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#492: initializing Health API
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/health
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#510: initializing aliases
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/node/node.go#338: initializing chains
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/vm/rWhpuQPF1kb72esV2momhMuTYGkEb1oL29pt2EBXWmSy4kxnT
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: 11111111111111111111111111111111LpoYY
    VMID:rWhpuQPF1kb72esV2momhMuTYGkEb1oL29pt2EBXWmSy4kxnT
INFO [08-10|16:56:54] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/vm.go#363: initializing Subnets
INFO [08-10|16:56:54] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/vm.go#349: initializing blockchains
INFO [08-10|16:56:54] <P Chain> /go/src/github.com/ava-labs/gecko/vms/platformvm/vm.go#327: Initializing last accepted block as 2gha7M3ebHr1Nm9tuz9rKXVsEpstqkcViFLhJmAdqUshY416W8
INFO [08-10|16:56:54] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:56:54] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/11111111111111111111111111111111LpoYY
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/network/peer.go#474: beacon attempting to connect with newer version avalanche/0.5.9. You may want to update your client
INFO [08-10|16:56:55] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [08-10|16:56:55] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:56:55] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:56:55] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with 2gha7M3ebHr1Nm9tuz9rKXVsEpstqkcViFLhJmAdqUshY416W8 as the last accepted block
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: rrEWX7gc7D9mwcdrdBxBTdqh1a7WDVsMuadhTZgyXfFcRz45L
    VMID:jvYyfQTxGMJLuGWa55kdP2p2zSUYsQ5Raupu4TW34ZAUBAbtq
INFO [08-10|16:56:55] <X Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#54: Initializing consensus engine
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/rrEWX7gc7D9mwcdrdBxBTdqh1a7WDVsMuadhTZgyXfFcRz45L
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/rrEWX7gc7D9mwcdrdBxBTdqh1a7WDVsMuadhTZgyXfFcRz45L/pubsub
INFO [08-10|16:56:55] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: zJytnh96Pc8rM337bBrtMvJDbEdDNjcXG3WkTNCiLp18ergm9
    VMID:mgj786NP7uDwBCcq6YwThhaN8FLyybkCa4zBWTQbNgmK6k9A6
INFO [08-10|16:56:56] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/zJytnh96Pc8rM337bBrtMvJDbEdDNjcXG3WkTNCiLp18ergm9/rpc
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/zJytnh96Pc8rM337bBrtMvJDbEdDNjcXG3WkTNCiLp18ergm9/ws
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: 1GHaaPbg1YBR4qiATuFNfL2j9StJwmddwXiwm1s9ts5KXvMai
    VMID:sqjdyTKUSrQs1YmKDTUbdUhdstSdtRTGRbUn8sqK8B6pkZkz1
INFO [08-10|16:56:56] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#54: Initializing consensus engine
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/1GHaaPbg1YBR4qiATuFNfL2j9StJwmddwXiwm1s9ts5KXvMai
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: jV7eZZh6Y2a35aaMLUGwBN1g2PNqfuuxLTSHu98EpHyPJDcQJ
    VMID:sqjchUjzDqDfBPGjfQq2tXW1UCwZTyvzAWHsNzF2cb1eVHt6w
INFO [08-10|16:56:56] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/jV7eZZh6Y2a35aaMLUGwBN1g2PNqfuuxLTSHu98EpHyPJDcQJ
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/chains/manager.go#187: creating chain:
    ID: am6cZ3MqzsbJG5mhNvrX2Z3w5uzRxZtgEacwhNqQ5p5KHAhtM
    VMID:tGas3T58KzdjLHhBDMnH2TvrddhqTji5iZAMZ3RXs2NLpSnhH
INFO [08-10|16:56:56] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#57: initializing consensus engine
INFO [08-10|16:56:56] /go/src/github.com/ava-labs/gecko/api/server.go#106: adding route /ext/bc/am6cZ3MqzsbJG5mhNvrX2Z3w5uzRxZtgEacwhNqQ5p5KHAhtM
INFO [08-10|16:56:58] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#225: AVM: GetBalance called with address: X-JMvox3UMrWpu2ASq8irunQ6na5fujXVDx assetID: AVA
INFO [08-10|16:57:00] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#225: AVM: GetBalance called with address: X-JMvox3UMrWpu2ASq8irunQ6na5fujXVDx assetID: AVA
INFO [08-10|16:57:02] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#225: AVM: GetBalance called with address: X-JMvox3UMrWpu2ASq8irunQ6na5fujXVDx assetID: AVA
INFO [08-10|16:57:03] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#225: AVM: GetBalance called with address: X-JMvox3UMrWpu2ASq8irunQ6na5fujXVDx assetID: AVA
INFO [08-10|16:57:03] <X Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 135 vertices in the accepted frontier
INFO [08-10|16:57:04] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [08-10|16:57:04] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:57:04] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:57:04] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with JJoWekhXrFYrcbw6t1wqC37vXT1QWUBskRyGskzBM6Q1sN8XJ as the last accepted block
INFO [08-10|16:57:04] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#164: Bootstrapping finished with no accepted frontier. This is likely a result of failing to be able to connect to the specified bootstraps, or no transactions have been issued on this chain yet
INFO [08-10|16:57:04] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#164: Bootstrapping finished with no accepted frontier. This is likely a result of failing to be able to connect to the specified bootstraps, or no transactions have been issued on this chain yet
INFO [08-10|16:57:04] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#292: finished fetching 0 vertices. executing transaction state transitions...
INFO [08-10|16:57:04] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [08-10|16:57:04] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#333: executed 0 operations
INFO [08-10|16:57:04] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#298: executing vertex state transitions...
INFO [08-10|16:57:04] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go#333: executed 0 operations
INFO [08-10|16:57:04] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#84: bootstrapping finished with 0 vertices in the accepted frontier
INFO [08-10|16:57:04] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:57:04] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:57:04] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with HQDeiNXCxDmETYpd7uRrnoKSeh71kS5cphKibCJMN6G1DmUFH as the last accepted block
INFO [08-10|16:57:04] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#230: bootstrapping finished fetching 0 blocks. executing state transitions...
INFO [08-10|16:57:04] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/bootstrapper.go#269: executed 0 blocks
INFO [08-10|16:57:04] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#111: bootstrapping finished with BhdXsMYpJsjGdgk1wqUWcukurCovwv9hpKMuLv7bJ9jVeSZJj as the last accepted block
^CINFO [08-10|16:57:21] /go/src/github.com/ava-labs/gecko/node/node.go#595: shutting down the node
INFO [08-10|16:57:21] <P Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:57:21] <P Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:57:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/engine/avalanche/transitive.go#111: shutting down consensus engine
INFO [08-10|16:57:21] <spdag Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:57:21] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:57:21] <spchain Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:57:21] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:57:21] <timestamp Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
INFO [08-10|16:57:21] <C Chain> /go/src/github.com/ava-labs/gecko/snow/engine/snowman/transitive.go#131: shutting down consensus engine
INFO [08-10|16:57:21] <C Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
WARN [08-10|16:57:22] /go/src/github.com/ava-labs/gecko/snow/networking/router/chain_router.go#349: timed out while shutting down the chains
INFO [08-10|16:57:22] /go/src/github.com/ava-labs/gecko/node/node.go#599: node shut down successfully
INFO [08-10|16:57:22] /go/src/github.com/ava-labs/gecko/nat/nat.go#138: Unmapped all ports
INFO [08-10|16:57:22] <X Chain> /go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go#67: finished shutting down chain
FATAL[08-10|16:57:22] <X Chain> /go/src/github.com/ava-labs/gecko/utils/logging/log.go#247: Panicing due to:
runtime error: invalid memory address or nil pointer dereference
From:
goroutine 455 [running]:
github.com/ava-labs/gecko/utils/logging.Stacktrace.String(0x4004b2cc00, 0xe20e4, 0x4004b2cd01)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/stack.go:20 +0x5c
fmt.(*pp).handleMethods(0x40025b2000, 0x73, 0x6400000001)
    /usr/lib/go-1.13/src/fmt/print.go:630 +0x260
fmt.(*pp).printArg(0x40025b2000, 0x8b9080, 0x40056cf800, 0x4000000073)
    /usr/lib/go-1.13/src/fmt/print.go:713 +0x20c
fmt.(*pp).doPrintf(0x40025b2000, 0x9d831e, 0x1c, 0x4004b2d318, 0x2, 0x2)
    /usr/lib/go-1.13/src/fmt/print.go:1030 +0x130
fmt.Sprintf(0x9d831e, 0x1c, 0x4004b2d318, 0x2, 0x2, 0x40059b24b0, 0x44)
    /usr/lib/go-1.13/src/fmt/print.go:219 +0x54
github.com/ava-labs/gecko/utils/logging.(*Log).format(0x40002763c0, 0x1, 0x9d831e, 0x1c, 0x4004b2d318, 0x2, 0x2, 0x0, 0x1)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/log.go:165 +0xdc
github.com/ava-labs/gecko/utils/logging.(*Log).log(0x40002763c0, 0x1, 0x9d831e, 0x1c, 0x4004b2d318, 0x2, 0x2)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/log.go:138 +0xe0
github.com/ava-labs/gecko/utils/logging.(*Log).Fatal(...)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/log.go:180
github.com/ava-labs/gecko/utils/logging.(*Log).StopOnPanic(0x40002763c0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/log.go:247 +0xc8
panic(0x8768a0, 0x13ab6e0)
    /usr/lib/go-1.13/src/runtime/panic.go:679 +0x194
github.com/ava-labs/gecko/snow/engine/avalanche/state.(*uniqueVertex).Height(0x4005cf9c80, 0x1)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/state/unique_vertex.go:129 +0x34
github.com/ava-labs/gecko/snow/engine/avalanche.priorityQueue.Less(0x400132b800, 0x6c, 0x100, 0x6b, 0x35, 0x1e940)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/vertex_heap.go:35 +0xc4
container/heap.up(0xc57160, 0x4001375f80, 0x6b)
    /usr/lib/go-1.13/src/container/heap/heap.go:93 +0x94
container/heap.Push(0xc57160, 0x4001375f80, 0x7e03c0, 0x4005cf9ea0)
    /usr/lib/go-1.13/src/container/heap/heap.go:54 +0x74
github.com/ava-labs/gecko/snow/engine/avalanche.(*maxHeightVertexHeap).Push(0x4004b2d678, 0xc5f260, 0x4005cf9c80, 0x13fa6d0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/vertex_heap.go:102 +0x108
github.com/ava-labs/gecko/snow/engine/avalanche.(*bootstrapper).process(0x4001547ce8, 0x40001e2900, 0x86, 0x87, 0x0, 0x0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go:193 +0x648
github.com/ava-labs/gecko/snow/engine/avalanche.(*bootstrapper).ForceAccepted(0x4001547ce8, 0x40025a9fb0, 0x47, 0x40000681e0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go:282 +0x200
github.com/ava-labs/gecko/snow/engine/common.(*Bootstrapper).Accepted(0x4001547e08, 0x4002cca840, 0x2, 0x40035ffa88, 0x40035ff928, 0x15b658)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go:169 +0x3c4
github.com/ava-labs/gecko/snow/engine/common.(*Bootstrapper).GetAcceptedFailed(0x4001547e08, 0x4002cca840, 0x2, 0x0, 0x0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go:123 +0x84
github.com/ava-labs/gecko/snow/networking/router.(*Handler).dispatchMsg(0x40002601c0, 0x6, 0x4002cca840, 0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go:140 +0x664
github.com/ava-labs/gecko/snow/networking/router.(*Handler).Dispatch(0x40002601c0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go:91 +0x248
github.com/ava-labs/gecko/utils/logging.(*Log).RecoverAndPanic(0x40002763c0, 0x4000457430)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/log.go:254 +0x58
created by github.com/ava-labs/gecko/chains.(*manager).createAvalancheChain
    /opt/gecko/go/src/github.com/ava-labs/gecko/chains/manager.go:444 +0x704

INFO [08-10|16:57:22] <X Chain> /go/src/github.com/ava-labs/gecko/vms/avm/service.go#225: AVM: GetBalance called with address: X-JMvox3UMrWpu2ASq8irunQ6na5fujXVDx assetID: AVA
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
    panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x50ca14]

goroutine 455 [running]:
github.com/ava-labs/gecko/utils/logging.(*Log).StopOnPanic(0x40002763c0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/log.go:249 +0xe8
panic(0x8768a0, 0x13ab6e0)
    /usr/lib/go-1.13/src/runtime/panic.go:679 +0x194
github.com/ava-labs/gecko/snow/engine/avalanche/state.(*uniqueVertex).Height(0x4005cf9c80, 0x1)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/state/unique_vertex.go:129 +0x34
github.com/ava-labs/gecko/snow/engine/avalanche.priorityQueue.Less(0x400132b800, 0x6c, 0x100, 0x6b, 0x35, 0x1e940)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/vertex_heap.go:35 +0xc4
container/heap.up(0xc57160, 0x4001375f80, 0x6b)
    /usr/lib/go-1.13/src/container/heap/heap.go:93 +0x94
container/heap.Push(0xc57160, 0x4001375f80, 0x7e03c0, 0x4005cf9ea0)
    /usr/lib/go-1.13/src/container/heap/heap.go:54 +0x74
github.com/ava-labs/gecko/snow/engine/avalanche.(*maxHeightVertexHeap).Push(0x4004b2d678, 0xc5f260, 0x4005cf9c80, 0x13fa6d0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/vertex_heap.go:102 +0x108
github.com/ava-labs/gecko/snow/engine/avalanche.(*bootstrapper).process(0x4001547ce8, 0x40001e2900, 0x86, 0x87, 0x0, 0x0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go:193 +0x648
github.com/ava-labs/gecko/snow/engine/avalanche.(*bootstrapper).ForceAccepted(0x4001547ce8, 0x40025a9fb0, 0x47, 0x40000681e0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/avalanche/bootstrapper.go:282 +0x200
github.com/ava-labs/gecko/snow/engine/common.(*Bootstrapper).Accepted(0x4001547e08, 0x4002cca840, 0x2, 0x40035ffa88, 0x40035ff928, 0x15b658)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go:169 +0x3c4
github.com/ava-labs/gecko/snow/engine/common.(*Bootstrapper).GetAcceptedFailed(0x4001547e08, 0x4002cca840, 0x2, 0x0, 0x0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go:123 +0x84
github.com/ava-labs/gecko/snow/networking/router.(*Handler).dispatchMsg(0x40002601c0, 0x6, 0x4002cca840, 0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go:140 +0x664
github.com/ava-labs/gecko/snow/networking/router.(*Handler).Dispatch(0x40002601c0)
    /opt/gecko/go/src/github.com/ava-labs/gecko/snow/networking/router/handler.go:91 +0x248
github.com/ava-labs/gecko/utils/logging.(*Log).RecoverAndPanic(0x40002763c0, 0x4000457430)
    /opt/gecko/go/src/github.com/ava-labs/gecko/utils/logging/log.go:254 +0x58
created by github.com/ava-labs/gecko/chains.(*manager).createAvalancheChain
    /opt/gecko/go/src/github.com/ava-labs/gecko/chains/manager.go:444 +0x704

By submitting this issue I agree to the Terms and Conditions of the Developer Accelerator Program.

aaronbuchwald commented 4 years ago

The fatal errors during shutdown are not abnormal (the panic has been fixed for the next release). What's happening is after you hit ctrl c, the node attempts to shut down each chain and if the chain times out while shutting down, the node continues to close all of the resources that it's using including the database, network, etc. In the latter case, this results in an unhandled database error and a panic (which has been fixed for the next release to allow a more graceful shutdown).

As for the X Chain not responding to queries, it looks like in both of these cases the X Chain has not finished bootstrapping. You should see a message from the X Chain that says Bootstrapping finished...

like you can see for the other chains which are responding when the X Chain has finished bootstrapping. After the X Chain finishes bootstrapping, all of the API calls should work normally.

otherpaco commented 4 years ago

Hello Aaron, the node ran since Denali Incentivized Testnet 24/7 without any issues. Then a month ago or so all the RAM was used 8GB plus 16GB swap. So I restarted the node somewhen around that time the X-Chain calls stopped working. Thats why I tried to start with a blank database. But since then the node ran for I think 2 weeks and is still not bootstrapped (Internet con. 100 Mbit/s)?!? Normally you get a 404 when you make a call to a chain that is not bootstrapped but I dont get any response. And if I make the call before the /go/src/github.com/ava-labs/gecko/snow/engine/common/bootstrapper.go#166 I get a correct response for older transactions.

otherpaco commented 4 years ago

Moved on to Everest an 0.6.2 no problems there