PlatONnetwork/PlatON-Go

节点更新二进制包重启后出现BAD BLOCK

niuxiaojie81 opened this issue · 3 comments

niuxiaojie81 commented

platon.log.zip

System information

PlatON version: 1.3.0-unstable
OS & Version: Linux
Commit hash : 8ddcea2

主网节点更换1.3.0-unstable二进制包，随后采用命令supervisorctl restart platon重启进程，日志出现BAD BLOCK，但后续能继续跟块

详情日志文件见附件（platon.log.zip）

niuxiaojie81 commented 
DEBUG[10-25|03:32:09.285|core/blockchain_cache.go:290]              Start execute block                      hash=0aefdc…03296b number=44324471      sealHash=6a9336…d6b7ff
INFO [10-25|03:32:09.285|core/blockchain_cache.go:214]              Make stateDB                             hash=2cb0be…78ddbb number=44324470      root=cd4d32…dbc76c


ERROR[10-25|03:32:09.322|core/state_transition.go:278]              VM returned with error                   blockNumber=44324471 txHash=e2bfa1…f538b2 err="execution reverted"
DEBUG[10-25|03:32:09.322|core/parallel_executor.go:247]             Execute contract transaction success     blockNumber=44324471 txHash=0xe2bfa1bccc6c4c7cf45aa9291cf1eac204b8b5c44f72e8cf1ad67ff771f538b2 gasPool=9399343 txGasLimit=400000  gasUsed=25433



INFO [10-25|03:32:09.772|cmd/utils/cmd.go:75]                       Got interrupt, shutting down... 
DEBUG[10-25|03:32:09.773|rpc/server.go:124]                         RPC server shutting down 
INFO [10-25|03:32:09.774|node/rpcstack.go:221]                      HTTP server stopped                      endpoint=[::]:6789
DEBUG[10-25|03:32:09.775|rpc/server.go:124]                         RPC server shutting down 
INFO [10-25|03:32:09.775|node/rpcstack.go:469]                      IPC endpoint closed                      url=/opt/platon/data/platon.ipc
DEBUG[10-25|03:32:09.775|rpc/server.go:124]                         RPC server shutting down 
DEBUG[10-25|03:32:09.775|rpc/client.go:574]                         RPC connection read error                err=EOF
INFO [10-25|03:32:09.776|eth/handler.go:261]                        Stopping PlatON protocol 
DEBUG[10-25|03:32:09.776|eth/downloader/downloader.go:836]          Reset ancient limit to zero 
INFO [10-25|03:32:09.788|eth/handler.go:278]                        PlatON protocol stopped 
INFO [10-25|03:32:09.788|core/tx_pool.go:556]                       Transaction pool stopped 
INFO [10-25|03:32:09.788|consensus/cbft/cbft.go:1594]               Pause cbft consensus                     epoch=103081 view=7
INFO [10-25|03:32:09.788|core/blockchain.go:870]                    Blockchain stopped 
INFO [10-25|03:32:09.788|consensus/cbft/cbft.go:1082]               Close cbft consensus                     epoch=103081 view=7
INFO [10-25|03:32:09.797|consensus/cbft/wal/wal_database.go:128]    Database closed                          Wal_database=/opt/platon/data/platon/wal/wal_meta
DEBUG[10-25|03:32:09.797|consensus/cbft/wal/wal_journal.go:253]     Close journal, flush data 
INFO [10-25|03:32:09.797|core/blockchain_reactor.go:127]            blockChain reactor loop exit 
INFO [10-25|03:32:09.797|core/blockchain_reactor.go:97]             blockchain_reactor closed 


DEBUG[10-25|03:32:09.838|core/parallel_executor.go:247]             Execute contract transaction success     blockNumber=44324471 txHash=0xb53a06a72f3041cca8d3c9016c0cff97e9f3a481a5eff8debb9f8a429cd8dc60 gasPool=8665824 txGasLimit=8000000 gasUsed=733519


DEBUG[10-25|03:32:09.838|x/handler/vrf_handler.go:123]              Storage previous nonce                   blockNumber=44324471 parentHash=2cb0be…78ddbb current hash=0aefdc…03296b nonce=023d0e5e08e0b97837728c8b008828c717a4aec01ae9d28b23570c992312e1caaf4ae94189ede7d3eabda098b6fe511f9b17393ee1cfe5f53bf00f97c1ccf833b5b78c3db611faea80adced53a90ac186d
DEBUG[10-25|03:32:09.838|x/handler/vrf_handler.go:139]              Storage previous nonce                   current blockNumber=44324471 parentHash=2cb0be…78ddbb current hash=0aefdc…03296b valueLength=201 MaxValidators=201
INFO [10-25|03:32:09.838|x/handler/vrf_handler.go:162]              Storage previous nonce Success           current blockNumber=44324471 parentHash=2cb0be…78ddbb current hash=0aefdc…03296b valueLength=201 MaxValidators=201 nonce=023d0e5e08e0b97837728c8b008828c717a4aec01ae9d28b23570c992312e1caaf4ae94189ede7d3eabda098b6fe511f9b17393ee1cfe5f53bf00f97c1ccf833b5b78c3db611faea80adced53a90ac186d firstNonce=cdfb2cdd0f359f491dd105aba07ef50df0e1ef612b77b667baf131b587cb8669 lastNonce=3d0e5e08e0b97837728c8b008828c717a4aec01ae9d28b23570c992312e1caaf
DEBUG[10-25|03:32:09.839|x/plugin/reward_plugin.go:470]             allocate package reward, delegate reward blockNumber=44324471 blockHash=0aefdc…03296b delegateReward=3254792349296887938   epochDelegateReward=68350639335234646698
DEBUG[10-25|03:32:09.839|x/plugin/reward_plugin.go:481]             allocate package reward,block reward     blockNumber=44324471 blockHash=0aefdc…03296b coinBase=lat1efchsqlkux2gjrzxp3h6zl320lpunm4ruzq2sj reward=1394911006841523402
DEBUG[10-25|03:32:09.839|core/blockchain_reactor.go:322]            Store ppos hash                          blockHash=0aefdc…03296b blockNumber=44324471 pposHash=abf2fadf0308693371ab587d19894ca209f2dc3d15a9fb9cb4d07844fdbd28e4
DEBUG[10-25|03:32:09.840|core/blockchain_reactor.go:328]            EndBlock StateDB root, end               blockHash=0aefdc…03296b blockNumber=44324471 root=acff3c…471196 pointer=0xc01f9e9680
DEBUG[10-25|03:32:09.840|core/parallel_state_processor.go:88]       Process end blocker cost time            blockNumber=44324471 blockHash=0aefdc…03296b
DEBUG[10-25|03:32:09.840|core/blockchain.go:1577]                   Execute block time                       blockNumber=44324471 blockHash=0aefdc…03296b time=554.3637ms
ERROR[10-25|03:32:09.840|core/blockchain.go:1780]                   
########## BAD BLOCK #########

通过日志分析，该BAD BLOCK出现在关闭进程的时候，44324471区块有两笔交易，分别在进程收到关闭信号前后执行

benbaley commented

错误的块：

EndBlock StateDB root, end               blockHash=0aefdc…03296b blockNumber=44324471 root=acff3c…471196

正确的块：

EndBlock StateDB root, end               blockHash="0aefdc…03296b" blockNumber=44324471 root="f83bc4…c45336"

看起来是旧的进程在退出过程中的处理出了问题

benbaley commented

fixed in #1974