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.

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

Restarting a non-mining node gives error when syncing with a mining node #78

Closed
larry-shyft opened this issue Sep 12, 2018 · 2 comments
Closed
Assignees
Labels
Closed Waiting for merge to staging This label means that a bug has been closed and is sitting in development.

Comments

@larry-shyft
Copy link

Hi Team,

When you stop and start a non-mining node, as soon as it starts syncing blockchain with other mining nodes, it reports error below. Possible reason: it tries to write a duplicate block into pg database

panic: pq: duplicate key value violates unique constraint "blocks_pkey"

System information
Geth version: shyftgeth version 1.8.3
OS & Version: Ubuntu

Expected behaviour
The non-mining node resumes block synchronization normally.

Actual behaviour
shyftgeth crashes from pg panic

Backtrace
INFO [09-11|18:22:14] Maximum peer count ETH=25 LES=0 total=25
INFO [09-11|18:22:14] Allocated cache and file handles database=/go/src/ShyftNetwork/go-empyrean/shyftData/geth/chaindata cache=16 handles=16
INFO [09-11|18:22:14] Persisted trie from memory database nodes=6 size=1.21kB time=14.365µs gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=0.00B
INFO [09-11|18:22:14] Successfully wrote genesis state database=chaindata hash=fa0194…2dafd4
INFO [09-11|18:22:14] Allocated cache and file handles database=/go/src/ShyftNetwork/go-empyrean/shyftData/geth/lightchaindata cache=16 handles=16
INFO [09-11|18:22:14] Persisted trie from memory database nodes=6 size=1.21kB time=12.77µs gcnodes=0 gcsize=0.00B gctime=0s livenodes=1 livesize=0.00B
INFO [09-11|18:22:14] Successfully wrote genesis state database=lightchaindata hash=fa0194…2dafd4

INFO [09-11|18:22:14] Maximum peer count ETH=25 LES=0 total=25
INFO [09-11|18:22:14] Starting peer-to-peer node instance=Geth/ShyftTestnetNode/v1.8.3-unstable-9fbf5f05/linux-amd64/go1.10.3
INFO [09-11|18:22:14] Allocated cache and file handles database=/go/src/ShyftNetwork/go-empyrean/shyftData/geth/chaindata cache=768 handles=1024
INFO [09-11|18:22:14] Initialised chain configuration config="{ChainID: 2147483647 Homestead: 1 DAO: DAOSupport: false EIP150: 2 EIP155: 3 EIP158: 3 Byzantium: 4 Constantinople: Engine: 1}%!(EXTRA params.EthashConfig=ethash)"
WARN [09-11|18:22:14] Ethash used in POW
INFO [09-11|18:22:14] Disk storage enabled for ethash caches dir=/go/src/ShyftNetwork/go-empyrean/shyftData/geth/ethash count=3
INFO [09-11|18:22:14] Disk storage enabled for ethash DAGs dir=./ethash/.ethash count=2
18000000000
INFO [09-11|18:22:14] Initialising Ethereum protocol versions="[63 62]" network=2147483647
WARN [09-11|18:22:14] Head state missing, repairing chain number=94480 hash=df798a…7298c2
INFO [09-11|18:22:17] Rewound blockchain to past state number=2 hash=da3641…798fa1
INFO [09-11|18:22:17] Loaded most recent local header number=94480 hash=df798a…7298c2 td=48891196144
INFO [09-11|18:22:17] Loaded most recent local full block number=2 hash=da3641…798fa1 td=266304
INFO [09-11|18:22:17] Loaded most recent local fast block number=94480 hash=df798a…7298c2 td=48891196144
INFO [09-11|18:22:17] Loaded local transaction journal transactions=0 dropped=0
INFO [09-11|18:22:17] Regenerated local transaction journal transactions=0 accounts=0
WARN [09-11|18:22:17] Blockchain not empty, fast sync disabled
INFO [09-11|18:22:17] Starting P2P networking
INFO [09-11|18:22:19] UDP listener up self=enode://db9636cf1e8a61c0d55301f4f92b49576f48bc793b87bc23acb2b95a1bfe3ba4404f8ca5ef8fe7539a587bdcecbec72aacfc3c067d426b488ede0afec291a225@[::]:31333
INFO [09-11|18:22:19] HTTP endpoint opened url=http://0.0.0.0:8545 cors=
vhosts=localhost
INFO [09-11|18:22:19] WebSocket endpoint opened url=ws://[::]:8546
INFO [09-11|18:22:19] RLPx listener up self=enode://db9636cf1e8a61c0d55301f4f92b49576f48bc793b87bc23acb2b95a1bfe3ba4404f8ca5ef8fe7539a587bdcecbec72aacfc3c067d426b488ede0afec291a225@[::]:31333
INFO [09-11|18:22:19] IPC endpoint opened url=/go/src/ShyftNetwork/go-empyrean/shyftData/geth.ipc
INFO [09-11|18:23:19] Block synchronisation started
panic: pq: duplicate key value violates unique constraint "blocks_pkey"

goroutine 5402 [running]:
github.com/ShyftNetwork/go-empyrean/core.InsertBlock(0xc43ef44a00, 0xc43f116690, 0x42, 0xc43f184a50, 0x2a, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/core/shyft_database_util.go:416 +0x49e
github.com/ShyftNetwork/go-empyrean/core.SWriteBlock(0xc43ef20ea0, 0x0, 0x0, 0x0, 0x400748734583b962, 0x6aa273ad681a3271)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/core/shyft_database_util.go:130 +0x7b1
github.com/ShyftNetwork/go-empyrean/core.(*BlockChain).WriteBlockWithState(0xc4202a4000, 0xc43ef20ea0, 0x0, 0x0, 0x0, 0xc43ef51950, 0x2, 0x0, 0x0)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/core/blockchain.go:1005 +0xe3d
github.com/ShyftNetwork/go-empyrean/core.(*BlockChain).insertChain(0xc4202a4000, 0xc43f0b0240, 0x41, 0x41, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/core/blockchain.go:1174 +0x16fa
github.com/ShyftNetwork/go-empyrean/core.(*BlockChain).InsertChain(0xc4202a4000, 0xc43f0b0240, 0x41, 0x41, 0x0, 0x0, 0x0)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/core/blockchain.go:1019 +0x67
github.com/ShyftNetwork/go-empyrean/eth/downloader.(*Downloader).importBlockResults(0xc4201efc80, 0xc43f0b0000, 0x41, 0x41, 0x41, 0x9b331e8df5e3c700)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/eth/downloader/downloader.go:1354 +0x431
github.com/ShyftNetwork/go-empyrean/eth/downloader.(*Downloader).processFullSyncContent(0xc4201efc80, 0xb7b8fc56f3384ea9, 0xc43d972798)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/eth/downloader/downloader.go:1328 +0x79
github.com/ShyftNetwork/go-empyrean/eth/downloader.(*Downloader).(github.com/ShyftNetwork/go-empyrean/eth/downloader.processFullSyncContent)-fm(0x627c55fa00000008, 0xfd23a0)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/eth/downloader/downloader.go:471 +0x2a
github.com/ShyftNetwork/go-empyrean/eth/downloader.(*Downloader).spawnSync.func1(0xc43ede0930, 0xc43ed5b380, 0xc43ecad500)
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/eth/downloader/downloader.go:484 +0x51
created by github.com/ShyftNetwork/go-empyrean/eth/downloader.(*Downloader).spawnSync
/go/src/github.com/ShyftEthereum/go-empyrean/build/_workspace/src/github.com/ShyftNetwork/go-empyrean/eth/downloader/downloader.go:484 +0xc3

@dbkbali @GregTheGreek @priom @dutterbutter @strangepowers @chris-shyft

@dutterbutter
Copy link

Provided Larry with a branch that does not hook into the Postgres instance while we tackle these issue in our PG refactor that is under development to ensure we are handling panics differently.

@larry-shyft
Copy link
Author

larry-shyft commented Oct 3, 2018

Based on Development branch, stop and restart of geth nodes works without errors on AWS ec2 instance.

ubuntu@ip-172-31-84-210:/myproject$ docker stop go-empyrean_shyftgeth_1
go-empyrean_shyftgeth_1
ubuntu@ip-172-31-84-210:
/myproject$ docker start go-empyrean_shyftgeth_1
go-empyrean_shyftgeth_1
ubuntu@ip-172-31-84-210:~/myproject$ docker logs --tail 120 go-empyrean_shyftgeth_1

[wait-for] [20181003170632] wait 'pg':'5432' up to '30'
[wait-for] [20181003170632] wait finish 'pg:5432' [0] seconds
[wait-for] [20181003170632] wait done with status=0
Skipping Genesis Initialization as already completed

INFO [10-03|17:06:32] Maximum peer count ETH=25 LES=0 total=25
INFO [10-03|17:06:32] Starting peer-to-peer node instance=Geth/ShyftTestnetNode/v1.8.3-unstable-fca85ebb/linux-amd64/go1.10.3
INFO [10-03|17:06:32] Allocated cache and file handles database=/go/src/ShyftNetwork/go-empyrean/shyftData/geth/chaindata cache=768 handles=1024
INFO [10-03|17:06:32] Initialised chain configuration config="{ChainID: 2147483647 Homestead: 1 DAO: DAOSupport: false EIP150: 2 EIP155: 3 EIP158: 3 Byzantium: 4 Constantinople: ShyftNetwork: 1 Engine: ethash}"
WARN [10-03|17:06:32] Ethash used in POW
INFO [10-03|17:06:32] Disk storage enabled for ethash caches dir=/go/src/ShyftNetwork/go-empyrean/shyftData/geth/ethash count=3
INFO [10-03|17:06:32] Disk storage enabled for ethash DAGs dir=./ethash/.ethash count=2
INFO [10-03|17:06:32] Initialising Ethereum protocol versions="[63 62]" network=2147483647
INFO [10-03|17:06:32] Loaded most recent local header number=94557 hash=b8237c…3203cb td=48961174121
INFO [10-03|17:06:32] Loaded most recent local full block number=94557 hash=b8237c…3203cb td=48961174121
INFO [10-03|17:06:32] Loaded most recent local fast block number=94557 hash=b8237c…3203cb td=48961174121
INFO [10-03|17:06:32] Loaded local transaction journal transactions=0 dropped=0
starting server on 8081
INFO [10-03|17:06:32] Regenerated local transaction journal transactions=0 accounts=0
WARN [10-03|17:06:32] Blockchain not empty, fast sync disabled
INFO [10-03|17:06:32] Starting P2P networking
INFO [10-03|17:06:34] UDP listener up self=enode://78bf96a17483bb904ebc2e8e2cf4349bc56fd865abc3e2740b182cc91855982bfc99ad53943fb6eecc84dc0433475eef4d557d480f04cdcf484f658567c4a312@[::]:31333
INFO [10-03|17:06:34] IPC endpoint opened url=/go/src/ShyftNetwork/go-empyrean/shyftData/geth.ipc
INFO [10-03|17:06:34] HTTP endpoint opened url=http://0.0.0.0:8545 cors=* vhosts=localhost
INFO [10-03|17:06:34] RLPx listener up self=enode://78bf96a17483bb904ebc2e8e2cf4349bc56fd865abc3e2740b182cc91855982bfc99ad53943fb6eecc84dc0433475eef4d557d480f04cdcf484f658567c4a312@[::]:31333
INFO [10-03|17:06:34] WebSocket endpoint opened url=ws://[::]:8546
INFO [10-03|17:06:35] Unlocked account address=0x43EC6d0942f7fAeF069F7F63D0384a27f529B062
INFO [10-03|17:06:36] Unlocked account address=0x9e602164C5826ebb5A6B68E4AFD9Cd466043dc4A
INFO [10-03|17:06:37] Unlocked account address=0x5Bd738164C61FB50eb12E227846CbaeF2dE965Aa
INFO [10-03|17:06:38] Unlocked account address=0xC04eE4131895F1d0C294D508AF65D94060AA42BB
INFO [10-03|17:06:38] Unlocked account address=0x07D899C4aC0c1725C35C5f816e60273B33a964F7
INFO [10-03|17:06:38] Transaction pool price threshold updated price=18000000000
INFO [10-03|17:06:38] Starting mining operation
INFO [10-03|17:06:38] Commit new mining work number=94558 txs=0 uncles=0 elapsed=171.541µs
INFO [10-03|17:06:41] Successfully sealed new block number=94558 hash=4c4ac2…005175
INFO [10-03|17:06:41] 🔨 mined potential block number=94558 hash=4c4ac2…005175
INFO [10-03|17:06:41] Commit new mining work number=94559 txs=0 uncles=0 elapsed=230.315µs
INFO [10-03|17:06:47] Successfully sealed new block number=94559 hash=f4a70f…5da541
INFO [10-03|17:06:47] 🔨 mined potential block number=94559 hash=f4a70f…5da541
INFO [10-03|17:06:47] Commit new mining work number=94560 txs=0 uncles=0 elapsed=171.571µs

@dbkbali dbkbali closed this as completed Oct 5, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Closed Waiting for merge to staging This label means that a bug has been closed and is sitting in development.
Projects
None yet
Development

No branches or pull requests

5 participants