avalanchego
avalanchego copied to clipboard
ava-labs
Failed verification during bootstrapping due to time is too far advanced
Describe the bug After running the node in docker (windows 11) on a overkill computer it always fails due to the issue below.
To Reproduce Start docker container, wait...
Expected behavior Not to fail.
Screenshots
/ _ \___ _______ | | _____ ____ ____ | |__ ____ ,_ o
/ /_\ \ \/ /\__ \ | | \__ \ / \_/ ___\| | \_/ __ \ / //\,
/ | \ / / __ \| |__/ __ \| | \ \___| Y \ ___/ \>> |
\____|__ /\_/ (____ /____(____ /___| /\___ >___| /\___ > \\
\/ \/ \/ \/ \/ \/ \/
INFO [01-18|11:36:44] database/leveldb/db.go#120: leveldb config: {"blockCacheCapacity":12582912,"blockSize":0,"compactionExpandLimitFactor":0,"compactionGPOverlapsFactor":0,"compactionL0Trigger":0,"compactionSourceLimitFactor":0,"compactionTableSize":0,"compactionTableSizeMultiplier":0,"compactionTableSizeMultiplierPerLevel":null,"compactionTotalSize":0,"compactionTotalSizeMultiplier":0,"openFilesCacheCapacity":64,"writeBuffer":6291456,"filterBitsPerKey":10}
WARN [01-18|11:36:45] app/process/process.go#119: UPnP or NAT-PMP router attach failed, you may not be listening publicly. Please confirm the settings in your router
INFO [01-18|11:36:45] node/node.go#1062: node version is: avalanche/1.7.3
INFO [01-18|11:36:45] node/node.go#1063: node ID is: NodeID-DsUT4oQUb1K5iTM3BxHuP3CRrsn2vvb6H
INFO [01-18|11:36:45] node/node.go#1064: current database version: v1.4.5
INFO [01-18|11:36:45] node/node.go#490: initializing API server
INFO [01-18|11:36:45] api/server/server.go#82: API created with allowed origins: [*]
INFO [01-18|11:36:45] node/node.go#808: initializing metrics API
INFO [01-18|11:36:45] api/server/server.go#218: adding route /ext/metrics
INFO [01-18|11:36:45] node/node.go#774: initializing keystore
INFO [01-18|11:36:45] node/node.go#785: initializing keystore API
INFO [01-18|11:36:45] api/server/server.go#218: adding route /ext/keystore
INFO [01-18|11:36:45] node/node.go#766: initializing SharedMemory
INFO [01-18|11:36:45] node/node.go#181: this node's IP is set to: "172.17.0.2:9651"
INFO [01-18|11:36:45] node/node.go#924: initializing Health API
INFO [01-18|11:36:45] api/server/server.go#218: adding route /ext/health
INFO [01-18|11:36:45] node/node.go#536: adding the default VM aliases
INFO [01-18|11:36:45] api/server/server.go#218: adding route /ext/vm/rWhpuQPF1kb72esV2momhMuTYGkEb1oL29pt2EBXWmSy4kxnT
INFO [01-18|11:36:45] api/server/server.go#218: adding route /ext/vm/jvYyfQTxGMJLuGWa55kdP2p2zSUYsQ5Raupu4TW34ZAUBAbtq
INFO [01-18|11:36:45] api/server/server.go#218: adding route /ext/vm/mgj786NP7uDwBCcq6YwThhaN8FLyybkCa4zBWTQbNgmK6k9A6/rpc
INFO [01-18|11:36:45] node/node.go#839: node config:
{"httpConfig":{"apiConfig":{"authConfig":{"apiRequireAuthToken":false},"indexerConfig":{"indexAPIEnabled":false,"indexAllowIncomplete":false},"ipcConfig":{"ipcAPIEnabled":false,"ipcPath":"/tmp","ipcDefaultChainIDs":null},"adminAPIEnabled":false,"infoAPIEnabled":true,"keystoreAPIEnabled":true,"metricsAPIEnabled":true,"healthAPIEnabled":true},"httpHost":"127.0.0.1","httpPort":9650,"httpsEnabled":false,"apiAllowedOrigins":["*"],"shutdownTimeout":10000000000,"shutdownWait":0},"ipConfig":{"ip":{"ip":"172.17.0.2","port":9651},"attemptedNATTraversal":true,"dynamicUpdateDuration":300000000000},"stakingConfig":{"uptimeRequirement":0.8,"minValidatorStake":2000000000000,"maxValidatorStake":3000000000000000,"minDelegatorStake":25000000000,"minDelegationFee":20000,"minStakeDuration":1209600000000000,"maxStakeDuration":31536000000000000,"stakeMintingPeriod":31536000000000000,"enableStaking":true,"disabledStakingWeight":100,"stakingKeyPath":"/root/.avalanchego/staking/staker.key","stakingCertPath":"/root/.avalanchego/staking/staker.crt"},"txFeeConfig":{"txFee":1000000,"createAssetTxFee":10000000,"createSubnetTxFee":1000000000,"createBlockchainTxFee":1000000000},"bootstrapConfig":{"retryBootstrap":true,"retryBootstrapWarnFrequency":50,"bootstrapBeaconConnectionTimeout":60000000000,"bootstrapMultiputMaxContainersSent":2000,"bootstrapMultiputMaxContainersReceived":2000,"bootstrapMaxTimeGetAncestors":50000000,"bootstrapIDs":["AaxT2P4uuPAHb7vAD8mNvjQ3jgyaV7tu9","Hr78Fy8uDYiRYocRYHXp4eLCYeb8x5UuM","BQEo5Fy1FRKLbX51ejqDd14cuSXJKArH2","A8jypu63CWp76STwKdqP6e9hjL675kdiG","A7GwTSd47AcDVqpTVj7YtxtjHREM33EJw"],"bootstrapIPs":[{"ip":"54.185.87.50","port":9651},{"ip":"54.93.182.129","port":9651},{"ip":"3.34.221.73","port":9651},{"ip":"3.104.107.241","port":9651},{"ip":"3.21.38.33","port":9651}]},"databaseConfig":{"path":"/root/.avalanchego/db/mainnet","name":"leveldb"},"avaxAssetID":"FvwEAhmxKfeiG8SnEvq42hc6whRyY3EFYAvebMqDNDGCgxN5Z","networkID":1,"enableAssertions":true,"enableCrypto":true,"healthCheckFreq":30000000000,"networkConfig":{"healthConfig":{"minConnectedPeers":1,"maxTimeSinceMsgReceived":60000000000,"maxTimeSinceMsgSent":60000000000,"maxPortionSendQueueBytesFull":0.9,"maxSendFailRate":0.9,"maxSendFailRateHalflife":10000000000},"peerListGossipConfig":{"peerListSize":20,"peerListGossipSize":50,"peerListStakerGossipFraction":2,"peerListGossipFreq":60000000000},"gossipConfig":{"gossipAcceptedFrontierSize":35,"gossipOnAcceptSize":20,"appGossipNonValidatorSize":0,"appGossipValidatorSize":10},"timeoutConfigs":{"getVersionTimeout":10000000000,"pingPongTimeout":30000000000,"readHandshakeTimeout":15000000000,"peerAliasTimeout":600000000000},"delayConfig":{"initialReconnectDelay":1000000000,"maxReconnectDelay":3600000000000},"throttlerConfig":{"inboundConnUpgradeThrottlerConfig":{"upgradeCooldown":10000000000,"maxRecentConnsUpgraded":2560},"inboundMsgThrottlerConfig":{"vdrAllocSize":33554432,"atLargeAllocSize":6291456,"nodeMaxAtLargeBytes":2097152,"bandwidthRefillRate":524288,"bandwidthMaxBurstRate":2097152,"maxProcessingMsgsPerNode":1024},"outboundMsgThrottlerConfig":{"vdrAllocSize":33554432,"atLargeAllocSize":6291456,"nodeMaxAtLargeBytes":2097152},"maxIncomingConnsPerSec":256},"dialerConfig":{"throttleRps":50,"connectionTimeout":30000000000},"namespace":"network","myNodeID":"DsUT4oQUb1K5iTM3BxHuP3CRrsn2vvb6H","myIP":{"ip":"172.17.0.2","port":9651},"networkID":1,"maxClockDifference":60000000000,"pingFrequency":22500000000,"allowPrivateIPs":true,"compressionEnabled":true,"whitelistedSubnets":[],"beacons":{},"validators":{},"uptimeMetricFreq":30000000000,"uptimeRequirement":0.8,"requireValidatorToConnect":false},"adaptiveTimeoutConfig":{"initialTimeout":5000000000,"minimumTimeout":2000000000,"maximumTimeout":10000000000,"timeoutCoefficient":2,"timeoutHalflife":300000000000},"benchlistConfig":{"threshold":10,"minimumFailingDuration":150000000000,"duration":900000000000,"maxPortion":0.08333333333333333,"peerSummaryEnabled":false},"profilerConfig":{"dir":"/root/.avalanchego/profiles","enabled":false,"freq":900000000000,"maxNumFiles":5},"loggingConfig":{"rotationInterval":86400000000000,"fileSize":8388608,"rotationSize":7,"flushSize":1,"disableLogging":false,"disableDisplaying":false,"disableContextualDisplaying":false,"disableFlushOnWrite":false,"assertions":false,"logLevel":"INFO","displayLevel":"INFO","displayHighlight":"COLORS"},"pluginDir":"/avalanchego/build/plugins","consensusParams":{"k":20,"alpha":15,"betaVirtuous":15,"betaRogue":20,"concurrentRepolls":4,"optimalProcessing":50,"maxOutstandingItems":1024,"maxItemProcessingTime":120000000000,"parents":5,"batchSize":30},"meterVMEnabled":true,"routerHealthConfig":{"maxDropRate":1,"maxDropRateHalflife":10000000000,"maxOutstandingRequests":1024,"maxOutstandingDuration":300000000000,"maxRunTimeRequests":10000000000},"consensusShutdownTimeout":5000000000,"consensusGossipFreq":10000000000,"whitelistedSubnets":[],"subnetConfigs":{}}
INFO [01-18|11:36:45] node/node.go#841: skipping admin API initialization because it has been disabled
INFO [01-18|11:36:45] node/node.go#889: initializing info API
INFO [01-18|11:36:45] api/server/server.go#218: adding route /ext/info
INFO [01-18|11:36:45] node/node.go#1001: skipping ipc API initialization because it has been disabled
INFO [01-18|11:36:45] node/node.go#1014: initializing chain aliases
INFO [01-18|11:36:46] node/node.go#1032: initializing API aliases
INFO [01-18|11:36:46] node/node.go#864: skipping profiler initialization because it has been disabled
INFO [01-18|11:36:46] node/node.go#476: initializing chains
INFO [01-18|11:36:46] chains/manager.go#245: creating chain:
ID: 11111111111111111111111111111111LpoYY
VMID:rWhpuQPF1kb72esV2momhMuTYGkEb1oL29pt2EBXWmSy4kxnT
INFO [01-18|11:36:48] <P Chain> vms/platformvm/vm.go#223: initializing last accepted block as 2G72CqXkK7Z8qkpvx8RuDBkiXm23fQ1D9AxXBDD4UxUaPjMJ7v
INFO [01-18|11:36:48] <P Chain> snow/engine/snowman/transitive.go#62: initializing consensus engine
INFO [01-18|11:36:48] <P Chain> snow/engine/common/bootstrapper.go#82: Starting bootstrap...
INFO [01-18|11:36:48] api/server/server.go#202: adding route /ext/bc/11111111111111111111111111111111LpoYY
INFO [01-18|11:36:48] api/server/server.go#114: HTTP API server listening on "127.0.0.1:9650"
INFO [01-18|11:36:55] <P Chain> snow/engine/common/bootstrapper.go#272: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [01-18|11:36:56] <P Chain> snow/engine/snowman/bootstrap/bootstrapper.go#361: bootstrapping fetched 862 blocks. Executing state transitions...
INFO [01-18|11:36:58] <P Chain> snow/engine/common/queue/jobs.go#168: executed 864 operations
INFO [01-18|11:36:59] chains/manager.go#245: creating chain:
ID: 2q9e4r6Mu3U68nU1fYjgbR6JvwrRx36CohpAX5UQxse55x1Q5
VMID:mgj786NP7uDwBCcq6YwThhaN8FLyybkCa4zBWTQbNgmK6k9A6
INFO [01-18|11:36:59] <C Chain> snow/engine/snowman/transitive.go#62: initializing consensus engine
INFO [01-18|11:36:59] <C Chain> snow/engine/common/bootstrapper.go#82: Starting bootstrap...
INFO [01-18|11:36:59] chains/manager.go#245: creating chain:
ID: 2oYMBNV4eNHyqk2fjjV5nVQLDbtmNJzq5s3qs3Lo6ftnC6FByM
VMID:jvYyfQTxGMJLuGWa55kdP2p2zSUYsQ5Raupu4TW34ZAUBAbtq
INFO [01-18|11:36:59] api/server/server.go#202: adding route /ext/bc/2q9e4r6Mu3U68nU1fYjgbR6JvwrRx36CohpAX5UQxse55x1Q5/rpc
INFO [01-18|11:36:59] api/server/server.go#202: adding route /ext/bc/2q9e4r6Mu3U68nU1fYjgbR6JvwrRx36CohpAX5UQxse55x1Q5/ws
INFO [01-18|11:36:59] api/server/server.go#202: adding route /ext/bc/2q9e4r6Mu3U68nU1fYjgbR6JvwrRx36CohpAX5UQxse55x1Q5/avax
INFO [01-18|11:36:59] <X Chain> vms/avm/vm.go#552: Fee payments are using Asset with Alias: AVAX, AssetID: FvwEAhmxKfeiG8SnEvq42hc6whRyY3EFYAvebMqDNDGCgxN5Z
INFO [01-18|11:36:59] <X Chain> vms/avm/vm.go#230: address transaction indexing is disabled
INFO [01-18|11:36:59] <X Chain> snow/engine/avalanche/transitive.go#65: initializing consensus engine
INFO [01-18|11:36:59] <X Chain> snow/engine/common/bootstrapper.go#82: Starting bootstrap...
INFO [01-18|11:36:59] api/server/server.go#202: adding route /ext/bc/2oYMBNV4eNHyqk2fjjV5nVQLDbtmNJzq5s3qs3Lo6ftnC6FByM
INFO [01-18|11:36:59] api/server/server.go#202: adding route /ext/bc/2oYMBNV4eNHyqk2fjjV5nVQLDbtmNJzq5s3qs3Lo6ftnC6FByM/wallet
INFO [01-18|11:36:59] api/server/server.go#202: adding route /ext/bc/2oYMBNV4eNHyqk2fjjV5nVQLDbtmNJzq5s3qs3Lo6ftnC6FByM/events
INFO [01-18|11:37:16] <X Chain> snow/engine/common/bootstrapper.go#272: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [01-18|11:37:17] <C Chain> snow/engine/common/bootstrapper.go#272: Bootstrapping started syncing with 1 vertices in the accepted frontier
INFO [01-18|11:37:19] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#430: bootstrapping fetched 1966 vertices. Executing transaction state transitions...
INFO [01-18|11:37:21] <X Chain> snow/engine/common/queue/jobs.go#168: executed 1966 operations
INFO [01-18|11:37:21] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#441: executing vertex state transitions...
INFO [01-18|11:37:22] <X Chain> snow/engine/common/queue/jobs.go#168: executed 1966 operations
INFO [01-18|11:37:28] health/service.go#130: "P" became healthy with: {"message":{"consensus":{},"vm":{"percentConnected":0.9940959632519885}},"timestamp":"2022-01-18T11:37:28.852319083Z","duration":163145,"contiguousFailures":0,"timeOfFirstFailure":null}
INFO [01-18|11:38:02] <C Chain> snow/engine/snowman/bootstrap/bootstrapper.go#326: fetched 5000 of 3462402 blocks
INFO [01-18|11:38:49] <C Chain> snow/engine/snowman/bootstrap/bootstrapper.go#326: fetched 10000 of 3462402 blocks
INFO [01-18|11:39:50] <C Chain> snow/engine/snowman/bootstrap/bootstrapper.go#326: fetched 15000 of 3462402 blocks
INFO [01-18|11:40:56] <C Chain> snow/engine/snowman/bootstrap/bootstrapper.go#326: fetched 20000 of 3462402 blocks
INFO [01-18|11:41:57] <C Chain> snow/engine/snowman/bootstrap/bootstrapper.go#361: bootstrapping fetched 24439 blocks. Executing state transitions...
INFO [01-18|11:43:32] <C Chain> snow/engine/common/queue/jobs.go#160: executed 2500 operations
INFO [01-18|11:44:53] <C Chain> snow/engine/common/queue/jobs.go#160: executed 5000 operations
INFO [01-18|11:46:21] <C Chain> snow/engine/common/queue/jobs.go#160: executed 7500 operations
INFO [01-18|11:47:38] <C Chain> snow/engine/common/queue/jobs.go#160: executed 10000 operations
INFO [01-18|11:48:48] <C Chain> snow/engine/common/queue/jobs.go#160: executed 12500 operations
INFO [01-18|11:49:52] <C Chain> snow/engine/common/queue/jobs.go#160: executed 15000 operations
INFO [01-18|11:50:51] <C Chain> snow/engine/common/queue/jobs.go#160: executed 17500 operations
INFO [01-18|11:52:03] <C Chain> snow/engine/common/queue/jobs.go#160: executed 20000 operations
INFO [01-18|11:53:09] <C Chain> snow/engine/common/queue/jobs.go#160: executed 22500 operations
INFO [01-18|11:54:17] <C Chain> snow/engine/common/queue/jobs.go#160: executed 25000 operations
INFO [01-18|11:55:27] <C Chain> snow/engine/common/queue/jobs.go#160: executed 27500 operations
INFO [01-18|11:56:40] <C Chain> snow/engine/common/queue/jobs.go#160: executed 30000 operations
INFO [01-18|11:57:52] <C Chain> snow/engine/common/queue/jobs.go#160: executed 32500 operations
INFO [01-18|11:59:08] <C Chain> snow/engine/common/queue/jobs.go#160: executed 35000 operations
INFO [01-18|12:00:27] <C Chain> snow/engine/common/queue/jobs.go#160: executed 37500 operations
INFO [01-18|12:01:40] <C Chain> snow/engine/common/queue/jobs.go#160: executed 40000 operations
INFO [01-18|12:03:07] <C Chain> snow/engine/common/queue/jobs.go#160: executed 42500 operations
INFO [01-18|12:04:27] <C Chain> snow/engine/common/queue/jobs.go#160: executed 45000 operations
INFO [01-18|12:06:02] <C Chain> snow/engine/common/queue/jobs.go#160: executed 47500 operations
INFO [01-18|12:07:24] <C Chain> snow/engine/common/queue/jobs.go#160: executed 50000 operations
INFO [01-18|12:08:36] <C Chain> snow/engine/common/queue/jobs.go#160: executed 52500 operations
INFO [01-18|12:09:43] <C Chain> snow/engine/common/queue/jobs.go#160: executed 55000 operations
INFO [01-18|12:10:56] <C Chain> snow/engine/common/queue/jobs.go#160: executed 57500 operations
INFO [01-18|12:12:20] <C Chain> snow/engine/common/queue/jobs.go#160: executed 60000 operations
INFO [01-18|12:13:35] <C Chain> snow/engine/common/queue/jobs.go#160: executed 62500 operations
INFO [01-18|12:14:52] <C Chain> snow/engine/common/queue/jobs.go#160: executed 65000 operations
INFO [01-18|12:16:12] <C Chain> snow/engine/common/queue/jobs.go#160: executed 67500 operations
INFO [01-18|12:17:29] <C Chain> snow/engine/common/queue/jobs.go#160: executed 70000 operations
INFO [01-18|12:18:43] <C Chain> snow/engine/common/queue/jobs.go#160: executed 72500 operations
INFO [01-18|12:19:51] <C Chain> snow/engine/common/queue/jobs.go#160: executed 75000 operations
INFO [01-18|12:21:07] <C Chain> snow/engine/common/queue/jobs.go#160: executed 77500 operations
INFO [01-18|12:22:21] <C Chain> snow/engine/common/queue/jobs.go#160: executed 80000 operations
INFO [01-18|12:23:37] <C Chain> snow/engine/common/queue/jobs.go#160: executed 82500 operations
INFO [01-18|12:25:02] <C Chain> snow/engine/common/queue/jobs.go#160: executed 85000 operations
INFO [01-18|12:26:19] <C Chain> snow/engine/common/queue/jobs.go#160: executed 87500 operations
INFO [01-18|12:27:39] <C Chain> snow/engine/common/queue/jobs.go#160: executed 90000 operations
INFO [01-18|12:29:01] <C Chain> snow/engine/common/queue/jobs.go#160: executed 92500 operations
INFO [01-18|12:30:13] <C Chain> snow/engine/common/queue/jobs.go#160: executed 95000 operations
INFO [01-18|12:31:28] <C Chain> snow/engine/common/queue/jobs.go#160: executed 97500 operations
INFO [01-18|12:32:37] <C Chain> snow/engine/common/queue/jobs.go#160: executed 100000 operations
INFO [01-18|12:33:40] <C Chain> snow/engine/common/queue/jobs.go#160: executed 102500 operations
INFO [01-18|12:34:44] <C Chain> snow/engine/common/queue/jobs.go#160: executed 105000 operations
INFO [01-18|12:35:55] <C Chain> snow/engine/common/queue/jobs.go#160: executed 107500 operations
INFO [01-18|12:37:11] <C Chain> snow/engine/common/queue/jobs.go#160: executed 110000 operations
INFO [01-18|12:38:27] <C Chain> snow/engine/common/queue/jobs.go#160: executed 112500 operations
INFO [01-18|12:39:16] <C Chain> snow/engine/common/queue/jobs.go#160: executed 115000 operations
INFO [01-18|12:40:08] <C Chain> snow/engine/common/queue/jobs.go#160: executed 117500 operations
INFO [01-18|12:41:14] <C Chain> snow/engine/common/queue/jobs.go#160: executed 120000 operations
INFO [01-18|12:42:12] <C Chain> snow/engine/common/queue/jobs.go#160: executed 122500 operations
INFO [01-18|12:43:09] <C Chain> snow/engine/common/queue/jobs.go#160: executed 125000 operations
INFO [01-18|12:44:12] <C Chain> snow/engine/common/queue/jobs.go#160: executed 127500 operations
INFO [01-18|12:45:13] <C Chain> snow/engine/common/queue/jobs.go#160: executed 130000 operations
INFO [01-18|12:46:01] <C Chain> snow/engine/common/queue/jobs.go#160: executed 132500 operations
INFO [01-18|12:47:01] <C Chain> snow/engine/common/queue/jobs.go#160: executed 135000 operations
INFO [01-18|12:47:51] <C Chain> snow/engine/common/queue/jobs.go#160: executed 137500 operations
INFO [01-18|12:48:43] <C Chain> snow/engine/common/queue/jobs.go#160: executed 140000 operations
INFO [01-18|12:49:36] <C Chain> snow/engine/common/queue/jobs.go#160: executed 142500 operations
INFO [01-18|12:50:24] <C Chain> snow/engine/common/queue/jobs.go#160: executed 145000 operations
INFO [01-18|12:51:11] <C Chain> snow/engine/common/queue/jobs.go#160: executed 147500 operations
INFO [01-18|12:52:06] <C Chain> snow/engine/common/queue/jobs.go#160: executed 150000 operations
INFO [01-18|12:52:52] <C Chain> snow/engine/common/queue/jobs.go#160: executed 152500 operations
INFO [01-18|12:53:48] <C Chain> snow/engine/common/queue/jobs.go#160: executed 155000 operations
INFO [01-18|12:54:46] <C Chain> snow/engine/common/queue/jobs.go#160: executed 157500 operations
INFO [01-18|12:55:40] <C Chain> snow/engine/common/queue/jobs.go#160: executed 160000 operations
INFO [01-18|12:56:36] <C Chain> snow/engine/common/queue/jobs.go#160: executed 162500 operations
INFO [01-18|12:57:39] <C Chain> snow/engine/common/queue/jobs.go#160: executed 165000 operations
ERROR[01-18|12:57:45] <P Chain> snow/engine/snowman/bootstrap/block_job.go#86: block pD3NmvxLZpD42co2TbD5xUX5sHRsbNUjJrqjPQAcd8VF2Vao9 failed verification during bootstrapping due to time is too far advanced
FATAL[01-18|12:57:45] <P Chain> snow/networking/router/handler.go#145: chain shutting down due to error "failed to execute job pD3NmvxLZpD42co2TbD5xUX5sHRsbNUjJrqjPQAcd8VF2Vao9 due to failed to verify block in bootstrapping: time is too far advanced" while processing message: (Op: multi_put, NodeID: NodeID-A8jypu63CWp76STwKdqP6e9hjL675kdiG, RequestID: 955, NumContainers: 688)
INFO [01-18|12:57:45] <P Chain> snow/engine/snowman/transitive.go#154: shutting down consensus engine
INFO [01-18|12:57:45] node/node.go#1164: shutting down node with exit code 1
INFO [01-18|12:57:45] ipcs/chainipc.go#101: shutting down chain IPCs
INFO [01-18|12:57:45] chains/manager.go#828: shutting down chain manager
INFO [01-18|12:57:45] snow/networking/router/chain_router.go#262: shutting down chain router
INFO [01-18|12:57:45] <X Chain> snow/engine/avalanche/transitive.go#136: shutting down consensus engine
INFO [01-18|12:57:45] <C Chain> snow/engine/common/queue/jobs.go#107: Interrupted execution after executing 165233 operations
INFO [01-18|12:57:45] <C Chain> snow/engine/snowman/transitive.go#154: shutting down consensus engine
INFO [01-18|12:57:46] network/network.go#655: shutting down network
WARN [01-18|12:57:46] health/service.go#133: "C" became unhealthy with: {"message":{"consensus":{},"vm":null},"error":{"message":"rpc error: code = Canceled desc = grpc: the client connection is closing"},"timestamp":"2022-01-18T11:42:09.632320093Z","duration":4537229104000,"contiguousFailures":1,"timeOfFirstFailure":"2022-01-18T11:42:09.632320093Z"}
INFO [01-18|12:57:46] node/node.go#1205: cleaning up plugin subprocesses
INFO [01-18|12:57:46] node/node.go#1208: finished node shutdown
INFO [01-18|12:57:46] nat/nat.go#152: Unmapped all ports
Operating System Windows 11 / Ubuntu 20.04 WSL
Additional context Processor AMD Ryzen 9 5950X 16-Core Processor, 3401 Mhz, 16 Core(s), 32 Logical Processor(s) 96gb RAM
By submitting this issue I agree to the Terms and Conditions of the Developer Accelerator Program.
I have the same problem. I have tried all versions 1.7x. Every time I started with a clean base.
INFO [01-25|20:27:53] api/server/server.go#203: adding route /ext/bc/2q9e4r6Mu3U68nU1fYjgbR6JvwrRx36CohpAX5UQxse55x1Q5/avax INFO [01-25|20:27:53] api/server/server.go#203: adding route /ext/bc/2q9e4r6Mu3U68nU1fYjgbR6JvwrRx36CohpAX5UQxse55x1Q5/rpc INFO [01-25|20:27:53] <X Chain> vms/avm/vm.go#451: initializing with AssetID FvwEAhmxKfeiG8SnEvq42hc6whRyY3EFYAvebMqDNDGCgxN5Z INFO [01-25|20:27:53] <X Chain> vms/avm/vm.go#437: Fee payments are using Asset with Alias: AVAX, AssetID: FvwEAhmxKfeiG8SnEvq42hc6whRyY3EFYAvebMqDNDGCgxN5Z INFO [01-25|20:27:53] <X Chain> vms/avm/vm.go#229: address transaction indexing is disabled INFO [01-25|20:27:53] <X Chain> snow/engine/avalanche/transitive.go#71: initializing consensus engine INFO [01-25|20:27:53] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#258: Starting bootstrap... INFO [01-25|20:27:53] api/server/server.go#203: adding route /ext/bc/2oYMBNV4eNHyqk2fjjV5nVQLDbtmNJzq5s3qs3Lo6ftnC6FByM INFO [01-25|20:27:53] api/server/server.go#203: adding route /ext/bc/2oYMBNV4eNHyqk2fjjV5nVQLDbtmNJzq5s3qs3Lo6ftnC6FByM/wallet INFO [01-25|20:27:53] api/server/server.go#203: adding route /ext/bc/2oYMBNV4eNHyqk2fjjV5nVQLDbtmNJzq5s3qs3Lo6ftnC6FByM/events INFO [01-25|20:28:06] <X Chain> snow/engine/common/bootstrapper.go#235: Bootstrapping started syncing with 1 vertices in the accepted frontier INFO [01-25|20:28:07] <C Chain> snow/engine/common/bootstrapper.go#235: Bootstrapping started syncing with 3 vertices in the accepted frontier INFO [01-25|20:28:13] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#388: fetched 5000 vertices INFO [01-25|20:28:23] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#388: fetched 10000 vertices INFO [01-25|20:28:27] <C Chain> snow/engine/snowman/bootstrap/bootstrapper.go#383: fetched 5000 of 10051027 blocks. ETA = 11h32m2.559811165s INFO [01-25|20:28:31] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#388: fetched 15000 vertices INFO [01-25|20:28:44] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#388: fetched 20000 vertices INFO [01-25|20:28:54] <X Chain> snow/engine/avalanche/bootstrap/bootstrapper.go#388: fetched 25000 vertices ERROR[01-25|20:29:00] <P Chain> snow/engine/snowman/bootstrap/block_job.go#86: block 27tgCaSuDqctiFBugQjEXQ1smMETcUmokRP8RqffELMPUpqyNu failed verification during bootstrapping due to time is too far advanced FATAL[01-25|20:29:00] <P Chain> snow/networking/router/handler.go#164: chain shutting down due to error "failed to execute job 27tgCaSuDqctiFBugQjEXQ1smMETcUmokRP8RqffELMPUpqyNu due to failed to verify block in bootstrapping: time is too far advanced" while processing message: (Op: ancestors, NodeID: NodeID-HsBEx3L71EHWSXaE6gvk2VsNntFEZsxqc, RequestID: 3148, NumContainers: 2000) INFO [01-25|20:29:00] <P Chain> snow/engine/snowman/transitive.go#282: shutting down consensus engine INFO [01-25|20:29:00] node/node.go#1218: shutting down node with exit code 1
"time is too far advanced" is reported due to blocks having a significantly higher timestamp than your local clock. Is your computer's local clock accurate?
I understand what he is complaining about. I do not understand why? The time is synchronized in the UTC. The start blocks cannot be later than the current time.
date
Wed Feb 9 08:08:20 UTC 2022
The same happened to me on my node today. The system clock is accurate. (The NodeID isn't mine). Avalanchego/1.7.8.
INFO [03-23|20:43:51.638] <C Chain> snow/engine/common/queue/jobs.go#173: executed 22500 of 2558449 operations. ETA = 130h37m24s
ERROR[03-23|20:45:12.964] <P Chain> snow/engine/snowman/bootstrap/block_job.go#86: block 21y7npz8pmqb7pbYX9kpfLArXJQQwRBR5Wz2BuEWikbV6xJ9xJ failed verification during bootstrapping due to time is too far advanced
FATAL[03-23|20:45:12.964] <P Chain> snow/networking/handler/handler.go#218: shutting down chain due to unexpected error: failed to execute job 21y7npz8pmqb7pbYX9kpfLArXJQQwRBR5Wz2BuEWikbV6xJ9xJ due to failed to verify block in bootstrapping: time is too far advanced while processing sync message: (Op: ancestors, NodeID: NodeID-GSgaA47umS1px2ohVjodW9621Ks63xDxD, RequestID: 870, NumContainers: 1375)
