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.

Sign up for GitHub

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

Jump to bottom

Incorrect exit on non-started block #774

Open
dimalit opened this issue May 4, 2023 · 9 comments · Fixed by #777
Open

Incorrect exit on non-started block #774

dimalit opened this issue May 4, 2023 · 9 comments · Fixed by #777
Assignees
@kladkogex
Labels
bug Something isn't working
Milestone
SKALE 4.1

Comments

@dimalit
Copy link
Contributor

dimalit commented May 4, 2023

Actual:

  1. 4 nodes
  2. exitGracefully() is called while consensus is waiting for new transactions (but there are no such)
  3. consensus waits for creation of new block and then exits

Expected:
consensus should exit immediately, because new block was not proposed yet
@kladkogex
Copy link
Contributor

Fixed

@kladkogex kladkogex self-assigned this May 16, 2023
@kladkogex kladkogex added this to the 2.2 milestone May 16, 2023
@kladkogex kladkogex moved this to Code Review in SKALE Engineering 🚀 May 16, 2023
@kladkogex kladkogex linked a pull request May 16, 2023 that will close this issue
774 and 775 incorrect exit #777
Merged
@dimalit
Copy link
Contributor Author

dimalit commented May 17, 2023

Looks it's still there:

2023-05-17 17:15:13.154607   http://127.0.0.1:35778 <<< {"id":39,"jsonrpc":"2.0","result":"0x6"}
2023-05-17 17:15:13.154739   Block stats:BN:6:BTS:1684343701:TXS:0:HDRS:11:LOGS:40:SENGS:1:TXRS:0:BLCKS:3:ACCS:69:BQS:1:BDS:39:TSS:0:UTX:0:VTX:0:CMM:13297
2023-05-17 17:15:13.155538   Block 7 DB usage is 1104. Piece DB usage is 7728 bytes
2023-05-17 17:15:13.155618      Imported and best 0 (#7). Has 0 siblings.
2023-05-17 17:15:13.157683   Insterted block with 0 transactions
2023-05-17 17:15:13.158657   Post state changed.
2023-05-17 17:15:13.158766   noteChanged: {chain}
2023-05-17 17:15:13.158833   Total unsafe time so far = 0 seconds
2023-05-17 17:15:13.158919   Successfully imported 0 of 0 transactions

2023-05-17 17:15:13.158985    sent_to_consensus = 0 got_from_consensus = 0 m_transaction_cache = 0 m_tq = 0 m_bcast_counter = 0
2023-05-17 17:15:13.161284   TRACEPOINT fetch_transactions 114
2023-05-17 17:15:14.152248   TRACEPOINT drop_bad_transactions 114
[2023-05-17 17:15:14.152] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:14.152] [4:main] [trace] 7:Proposal step 1: wrote proposal header
2023-05-17 17:15:14.153314   http://127.0.0.1:35778 >>> {"id":40,"jsonrpc":"2.0","method":"eth_blockNumber","params":[]}
[2023-05-17 17:15:14.153] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:14.153] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:14.154] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
2023-05-17 17:15:14.154055   http://127.0.0.1:35778 <<< {"id":40,"jsonrpc":"2.0","result":"0x7"}
2023-05-17 17:15:14.161350   http://127.0.0.1:35778 >>> {"id":41,"jsonrpc":"2.0","method":"eth_blockNumber","params":[]}
2023-05-17 17:15:14.162093   http://127.0.0.1:35778 <<< {"id":41,"jsonrpc":"2.0","result":"0x7"}
2023-05-17 17:15:14.164278   Skaled status: setExitState: StartAgain to false
2023-05-17 17:15:14.164422   THREADS timer started
2023-05-17 17:15:14.164789   Skaled status: setExitState: StartFromSnapshot to false
2023-05-17 17:15:14.221880   Skaled status: setExitState: ClearDataDir to false
[2023-05-17 17:15:15.161] [4:catchup] [debug] 7:Catchupc step 0: requesting blocks after 7
[2023-05-17 17:15:15.161] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:15.162] [4:catchup] [debug] 7:Catchupc step 1: wrote catchup request
[2023-05-17 17:15:15.162] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:15.162] [4:main] [trace] 7:Read JSON header{"count":0,"status":4,"substatus":14,"type":"BlckCatchupRsp"}
[2023-05-17 17:15:15.162] [4:catchup] [debug] 7:Catchupc step 2: read catchup response requestHeader
[2023-05-17 17:15:15.162] [4:catchup] [debug] 7:Catchupc got response::no missing blocks
[2023-05-17 17:15:15.163] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:15.163] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:15.163] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
[2023-05-17 17:15:16.063] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:16.064] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:16.127] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:16.127] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:16.127] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
2023-05-17 17:15:16.467897   SKALE NETWORK BROWSER refreshing(stop) did cleared/forgot dispatch/job
2023-05-17 17:15:16.472184   Will stop proxygen/HTTP server on address 127.0.0.4 and port 1234=0x000004d2/nfo...
2023-05-17 17:15:16.472355   OK, stopped proxygen/HTTP server on address 127.0.0.4 and port 1234=0x000004d2/nfo
2023-05-17 17:15:16.472449   Will stop proxygen/HTTP server on address 127.0.0.4 and port 1240=0x000004d8/std...
2023-05-17 17:15:16.472547   OK, stopped proxygen/HTTP server on address 127.0.0.4 and port 1240=0x000004d8/std
2023-05-17 17:15:16.473412   Skaled status: setSubsystemRunning: Rpc to false

2023-05-17 17:15:17.477571   Stop worker 1003 ms
[2023-05-17 17:15:17.477] [4:main] [trace] 7:Proposal step 0: Starting block proposal
2023-05-17 17:15:17.477766   1 before exitGracefully()
2023-05-17 17:15:17.477854   Exit requested with signal 15 and exit code 0
[2023-05-17 17:15:17.477] [4:consensus] [info] 7:Consensus engine exiting: blocking exit exitGracefully called by skaled
[2023-05-17 17:15:17.478] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:17.478] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:17.479] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:17.479] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
[2023-05-17 17:15:18.482] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:18.482] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:19.411] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:19.411] [4:pending] [trace] 7:Created proposal, transactions:0
[2023-05-17 17:15:19.412] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:19.412] [4:proposal] [trace] 7:addBlockProposal blockID_=8 proposerIndex=4
[2023-05-17 17:15:19.412] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
[2023-05-17 17:15:20.334] [4:catchup] [debug] 7:Catchupc step 0: requesting blocks after 7
[2023-05-17 17:15:20.334] [4:main] [debug] 7:PROPOSING BLOCK NUMBER:8
[2023-05-17 17:15:20.334] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","proposerIndex":3,"proposerNodeID":3,"schainID":1,"sig":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","sr":"46320509353513273106582423493727320152202237096314791991810382902766530930981","status":5,"substatus":3,"timeStamp":1684343719,"timeStampMs":441,"txCount":0,"type":"BlckPrpslReq"}
[2023-05-17 17:15:20.335] [4:catchup] [debug] 7:Catchupc step 1: wrote catchup request
[2023-05-17 17:15:20.335] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:20.335] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:20.336] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:20.336] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:20.336] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
[2023-05-17 17:15:21.253] [4:catchup] [debug] 7:Catchupc step 2: can not read catchup response
[2023-05-17 17:15:21.253] [4:main] [trace] 7:Adding sigshare
[2023-05-17 17:15:21.253] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:21.253] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:21.253] [4:main] [error] 7:!Exception: CatchupClientAgent:Catchupc step 2: can not read catchup response
[2023-05-17 17:15:21.253] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:21.253] [4:main] [error] 7: !Caused by: nlohmann:Read catchup response:Could not read header len from:127.0.0.3
[2023-05-17 17:15:21.253] [4:main] [error] 7:  !Caused by: IO:Read returned error:Interrupted system call
[2023-05-17 17:15:21.254] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:21.254] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:21.254] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:21.255] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:21.255] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:21.255] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
[2023-05-17 17:15:21.973] [4:main] [debug] 7:Calculating missing hashes
[2023-05-17 17:15:21.973] [4:main] [error] 7:!Exception: nlohmann:Read proposal resp:Could not read header len from:127.0.0.1
[2023-05-17 17:15:21.973] [4:main] [error] 7: !Caused by: IO:Read returned error:Interrupted system call
[2023-05-17 17:15:21.973] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:21.973] [4:main] [error] 7:!Exception: nlohmann:Read proposal resp:Could not read header len from:127.0.0.3
[2023-05-17 17:15:21.974] [4:main] [error] 7:!Exception: std:Could not send missing hashes request requestHeader
[2023-05-17 17:15:21.974] [4:main] [error] 7: !Caused by: IO:Read returned error:Interrupted system call
[2023-05-17 17:15:21.974] [4:main] [error] 7: !Caused by: IO:Destination unexpectedly closed connection
[2023-05-17 17:15:21.974] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:21.974] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","proposerIndex":1,"proposerNodeID":1,"schainID":1,"sig":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","sr":"46320509353513273106582423493727320152202237096314791991810382902766530930981","status":5,"substatus":3,"timeStamp":1684343719,"timeStampMs":569,"txCount":0,"type":"BlckPrpslReq"}
[2023-05-17 17:15:21.975] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:21.975] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:21.975] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
[2023-05-17 17:15:22.888] [4:main] [debug] 7:Calculating missing hashes
[2023-05-17 17:15:22.888] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:22.888] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:22.888] [4:main] [error] 7:!Exception: std:Could not send missing hashes request requestHeader
[2023-05-17 17:15:22.888] [4:consensus] [debug] 7:4ROUND_COMPLETE:BLOCK:7:ROUND:1
[2023-05-17 17:15:22.889] [4:main] [error] 7: !Caused by: IO:Destination unexpectedly closed connection
[2023-05-17 17:15:22.889] [4:consensus] [debug] 7::PROPOSER:4:DECIDED VALUE1:ROUND:1
[2023-05-17 17:15:22.889] [4:consensus] [debug] 7:Decided value: 1 for blockid:7 proposer:4
[2023-05-17 17:15:22.889] [4:consensus] [debug] 7:Got child message 7:4
[2023-05-17 17:15:22.889] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","proposerIndex":3,"proposerNodeID":3,"schainID":1,"sig":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","sr":"46320509353513273106582423493727320152202237096314791991810382902766530930981","status":5,"substatus":3,"timeStamp":1684343719,"timeStampMs":441,"txCount":0,"type":"BlckPrpslReq"}
[2023-05-17 17:15:22.889] [4:main] [debug] 7:Calculating missing hashes
[2023-05-17 17:15:22.890] [4:main] [debug] 7:Server: No missing partial hashes
[2023-05-17 17:15:22.890] [4:main] [debug] 7:Storing block proposal
[2023-05-17 17:15:22.890] [4:proposal] [trace] 7:addBlockProposal blockID_=8 proposerIndex=3
[2023-05-17 17:15:23.608] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","proposerIndex":3,"proposerNodeID":3,"schainID":1,"status":5,"substatus":3,"thrSig":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","type":"DAPrfReq"}
[2023-05-17 17:15:23.608] [4:main] [error] 7:!Exception: nlohmann:Read proposal resp:Could not read header len from:127.0.0.2
[2023-05-17 17:15:23.608] [4:main] [error] 7: !Caused by: IO:Read returned error:Interrupted system call
[2023-05-17 17:15:23.608] [4:main] [trace] 7:Adding daProof
[2023-05-17 17:15:24.523] [4:proposal] [trace] 7:Got DA proof
[2023-05-17 17:15:24.523] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","proposerIndex":1,"proposerNodeID":1,"schainID":1,"sig":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","sr":"46320509353513273106582423493727320152202237096314791991810382902766530930981","status":5,"substatus":3,"timeStamp":1684343719,"timeStampMs":569,"txCount":0,"type":"BlckPrpslReq"}
[2023-05-17 17:15:24.524] [4:main] [debug] 7:Calculating missing hashes
[2023-05-17 17:15:24.525] [4:main] [error] 7:!Exception: std:Could not send missing hashes request requestHeader
[2023-05-17 17:15:24.525] [4:main] [error] 7: !Caused by: IO:Destination unexpectedly closed connection
[2023-05-17 17:15:25.530] [4:main] [trace] 7:Read JSON header{"blockID":7,"nodeID":3,"schainID":1,"status":5,"substatus":3,"type":"BlckCatchupReq"}
[2023-05-17 17:15:25.530] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:25.530] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:25.530] [4:main] [debug] 7:Catchups: sChain->getCommittedBlockID() <= block_id(blockID)
[2023-05-17 17:15:25.530] [4:main] [trace] 7:Read JSON header{"blockID":7,"nodeID":1,"schainID":1,"status":5,"substatus":3,"type":"BlckCatchupReq"}
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:25.531] [4:catchup] [debug] 7:Server step 2: sent catchup response header
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:25.531] [4:catchup] [debug] 7:Server step 3: response completed: no blocks sent
[2023-05-17 17:15:25.531] [4:main] [debug] 7:Catchups: sChain->getCommittedBlockID() <= block_id(blockID)
[2023-05-17 17:15:25.531] [4:catchup] [debug] 7:Server step 2: sent catchup response header
[2023-05-17 17:15:25.531] [4:catchup] [debug] 7:Server step 3: response completed: no blocks sent
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Read JSON header{"status":1,"substatus":0,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Read JSON header{"status":1,"substatus":0,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal step 3: sent partial hashes
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal step 3: sent partial hashes
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Read JSON header{"count":0,"status":5,"substatus":3,"type":"MsngTxsReq"}
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Read JSON header{"count":0,"status":5,"substatus":3,"type":"MsngTxsReq"}
[2023-05-17 17:15:25.531] [4:proposal] [trace] 7:Push agent processed missing transactions header
[2023-05-17 17:15:25.531] [4:proposal] [trace] 7:Push agent processed missing transactions header
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal complete::no missing transactions
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Proposal complete::no missing transactions
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Read JSON header{"pk":"","pks":"","sig":"956a5113de56a5525035d4e4975ce194a7b7d7439853e8938f57aededa18c0fe","sss":"06e067b45f69d07af55824df4422aa499f4d8a7f84be6ea055f319156b477033","status":0,"substatus":0,"type":"SigShareRsp"}
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Read JSON header{"pk":"","pks":"","sig":"956a5113de56a5525035d4e4975ce194a7b7d7439853e8938f57aededa18c0fe","sss":"06e067b45f69d07af55824df4422aa499f4d8a7f84be6ea055f319156b477033","status":0,"substatus":0,"type":"SigShareRsp"}
[2023-05-17 17:15:25.531] [4:main] [trace] 7:Adding sigshare
[2023-05-17 17:15:26.347] [4:catchup] [debug] 7:Catchupc step 0: requesting blocks after 7
[2023-05-17 17:15:26.347] [4:main] [trace] 7:Adding sigshare
[2023-05-17 17:15:26.347] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","proposerIndex":1,"proposerNodeID":1,"schainID":1,"sig":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","sr":"46320509353513273106582423493727320152202237096314791991810382902766530930981","status":5,"substatus":3,"timeStamp":1684343719,"timeStampMs":569,"txCount":0,"type":"BlckPrpslReq"}
[2023-05-17 17:15:26.347] [4:catchup] [debug] 7:Catchupc step 1: wrote catchup request
[2023-05-17 17:15:26.347] [4:main] [debug] 7:Calculating missing hashes
[2023-05-17 17:15:26.348] [4:main] [debug] 7:Server: No missing partial hashes
[2023-05-17 17:15:26.348] [4:main] [debug] 7:Storing block proposal
[2023-05-17 17:15:26.348] [4:main] [trace] 7:Read JSON header{"count":0,"status":4,"substatus":14,"type":"BlckCatchupRsp"}
[2023-05-17 17:15:26.348] [4:catchup] [debug] 7:Catchupc step 2: read catchup response requestHeader
[2023-05-17 17:15:26.348] [4:proposal] [trace] 7:addBlockProposal blockID_=8 proposerIndex=1
[2023-05-17 17:15:26.348] [4:catchup] [debug] 7:Catchupc got response::no missing blocks
[2023-05-17 17:15:26.411] [4:main] [trace] 7:Merged signature
[2023-05-17 17:15:26.411] [4:main] [trace] 7:Adding daProof
[2023-05-17 17:15:26.415] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:26.415] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:26.415] [4:main] [trace] 7:DA proof step 1: wrote request header
[2023-05-17 17:15:26.415] [4:main] [trace] 7:DA proof step 1: wrote request header
[2023-05-17 17:15:26.415] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","proposerIndex":1,"proposerNodeID":1,"schainID":1,"status":5,"substatus":3,"thrSig":"003cf34bacff8c6e3a4bd6eefd1564a60ed33ce7265c8dc5491376b646e1c12e","type":"DAPrfReq"}
[2023-05-17 17:15:26.415] [4:main] [trace] 7:Adding daProof
[2023-05-17 17:15:26.416] [4:main] [trace] 7:Created proposal vector
[2023-05-17 17:15:26.418] [4:main] [info] 7:CONSENSUS_STARTED:PROPOSING: 1011
[2023-05-17 17:15:26.418] [4:main] [debug] 7:Got proposed block set for block:8
[2023-05-17 17:15:26.418] [4:main] [debug] 7:StartConsensusIfNeeded BLOCK NUMBER:8
[2023-05-17 17:15:26.418] [4:main] [debug] 7:Starting consensus for block id:8
[2023-05-17 17:15:26.418] [4:consensus] [debug] 7:CONSENSUS START:BLOCK:8
[2023-05-17 17:15:26.418] [4:proposal] [trace] 7:Got DA proof
[2023-05-17 17:15:26.419] [4:main] [trace] 7:Read JSON header{"status":0,"substatus":0,"type":"DAPrfRsp"}
[2023-05-17 17:15:26.419] [4:main] [trace] 7:DAProof step 2: read response
[2023-05-17 17:15:26.421] [4:main] [trace] 7:Read JSON header{"status":0,"substatus":0,"type":"DAPrfRsp"}
[2023-05-17 17:15:26.421] [4:main] [trace] 7:DAProof step 2: read response
[2023-05-17 17:15:26.433] [4:consensus] [debug] 7:1ROUND_COMPLETE:BLOCK:8:ROUND:0
[2023-05-17 17:15:26.433] [4:consensus] [debug] 7:1:NEW ROUND:BLOCK:1:ROUND:0
[2023-05-17 17:15:26.435] [4:consensus] [debug] 7:2ROUND_COMPLETE:BLOCK:8:ROUND:0
[2023-05-17 17:15:26.435] [4:consensus] [debug] 7:2:NEW ROUND:BLOCK:0:ROUND:0
[2023-05-17 17:15:26.437] [4:consensus] [debug] 7:3ROUND_COMPLETE:BLOCK:8:ROUND:0
[2023-05-17 17:15:26.437] [4:consensus] [debug] 7:3:NEW ROUND:BLOCK:1:ROUND:0
[2023-05-17 17:15:26.438] [4:consensus] [debug] 7:4ROUND_COMPLETE:BLOCK:8:ROUND:0
[2023-05-17 17:15:26.438] [4:consensus] [debug] 7:4:NEW ROUND:BLOCK:1:ROUND:0
[2023-05-17 17:15:27.362] [4:main] [trace] 7:Read JSON header{"blockID":8,"hash":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","proposerIndex":3,"proposerNodeID":3,"schainID":1,"status":5,"substatus":3,"thrSig":"0c0b9a7ef90b13e3ff1016863dfc9e39cd1dcf3268fa962f015c5a2c4da045ca","type":"DAPrfReq"}
[2023-05-17 17:15:27.362] [4:main] [trace] 7:Proposal step 0: Starting block proposal
[2023-05-17 17:15:27.362] [4:consensus] [debug] 7:1ROUND_COMPLETE:BLOCK:8:ROUND:1
[2023-05-17 17:15:27.362] [4:consensus] [debug] 7::PROPOSER:1:DECIDED VALUE1:ROUND:1
[2023-05-17 17:15:27.362] [4:consensus] [debug] 7:Decided value: 1 for blockid:8 proposer:1
[2023-05-17 17:15:27.362] [4:consensus] [debug] 7:Got child message 8:1
[2023-05-17 17:15:27.362] [4:main] [trace] 7:Proposal step 1: wrote proposal header
[2023-05-17 17:15:27.363] [4:proposal] [trace] 7:Got DA proof
[2023-05-17 17:15:27.363] [4:main] [trace] 7:Read JSON header{"status":3,"substatus":10,"type":"BlckPrpslRsp"}
[2023-05-17 17:15:27.363] [4:consensus] [info] 7:CONSENSUS_COMPLETED:STATS::16:10:0:3:0:0:0:0:0:0:0:0:0:0:0:0
[2023-05-17 17:15:27.363] [4:consensus] [info] 7:BLOCK_DECIDED:PROPOSER:1:BID:8:STATS:|1|D1R1P5L764|2|*|3|*|4|*|| Now signing block ...
[2023-05-17 17:15:27.363] [4:main] [trace] 7:Proposal step 2: read proposal response
[2023-05-17 17:15:27.364] [4:main] [trace] 7:Proposal Server terminated proposal push:3:10
[2023-05-17 17:15:27.426] [4:consensus] [info] 7:BLOCK_DECIDED_AND_SIGNED:PRPSR:1:BID:8:SIG:7a745b3468c79fb869a8373748082a68cd192bf53fadf9decbb343741f4c7c8c
[2023-05-17 17:15:27.426] [4:main] [info] 7:BLOCK_COMMITED: PRPSR:1:BID: 8:ROOT:46320509353513273106582423493727320152202237096314791991810382902766530930981:HASH:003cf34b:BLOCK_TXS:0:DMSG:0:TPRPS:5:MPRPS:2:RPRPS:2:TXS:0:TXLS:4:MGS:22:INSTS:34:BPS:0:HDRS:9:SOCK:1:FDS:256:PRT:13259:BTA:6514:BSA:0:TPS:0:LWT:0:LRT:0:LWC:246:LRC:313:KNWN:0:CONS:0:DSDS:0:SET:0:SBT:0:SEC:8:SBC:8:ZSC:0:EPT:9:STAMP:1684343719.569
[2023-05-17 17:15:27.432] [4:main] [trace] 7:Save price for block8
2023-05-17 17:15:27.436941   createBlock ID = #8

@DmytroNazarenko DmytroNazarenko added the bug Something isn't working label May 18, 2023
@DmytroNazarenko DmytroNazarenko removed this from the 2.2 milestone May 18, 2023
@DmytroNazarenko
Copy link
Contributor

Related to skalenetwork/skaled#1425

@dimalit
Copy link
Contributor Author

dimalit commented May 18, 2023

As of consensus 0ea0cae:

2023-05-18 16:50:51.473597   Block sealed #6 (#817bd8b2…)
...
2023-05-18 16:50:52.017935   THREADS timer started
...
[2023-05-18 16:50:56.050] [4:consensus] [info] 6:Consensus engine exiting: asynchronous exit exitGracefully called by skaled
...
[2023-05-18 16:50:58.083] [4:pending] [trace] 6:Created proposal, transactions:0
...
[2023-05-18 16:50:58.147] [4:main] [debug] 6:PROPOSING BLOCK NUMBER:7
...
[2023-05-18 16:51:34.021] [4:main] [info] 7:BLOCK_COMMITED: PRPSR:0:BID: 8:ROOT:0:HASH:cad2c15d:BLOCK_TXS:0:DMSG:0:TPRPS:5:MPRPS:3:RPRPS:1:TXS:0:TXLS:4:MGS:27:INSTS:34:BPS:0:HDRS:5:SOCK:0:FDS:255:PRT:30046:BTA:7670:BSA:0:TPS:0:LWT:0:LRT:0:LWC:260:LRC:322:KNWN:0:CONS:0:DSDS:0:SET:0:SBT:0:SEC:8:SBC:11:ZSC:0:EPT:4:STAMP:1684428656.536
...
[2023-05-18 16:51:34.027] [4:main] [info] 7:Exiting on block boundary after processing block 7

So, when consensus receives exitGracefully() call BEFORE proposing block 7, it should abort this proposal and exit (at block 6).
But actually it creates even block 8, though pretends it is exiting after creating block 7.

@github-project-automation github-project-automation bot moved this from Code Review to Ready For Release Candidate in SKALE Engineering 🚀 May 22, 2023
@DmytroNazarenko
Copy link
Contributor

skaled: 3.17.0-beta.1

@DmytroNazarenko DmytroNazarenko moved this from Ready For Release Candidate to Merged To Release Candidate in SKALE Engineering 🚀 Jun 21, 2023
@EvgeniyZZ EvgeniyZZ moved this from Merged To Release Candidate to QA in SKALE Engineering 🚀 Jun 21, 2023
@oleksandrSydorenkoJ
Copy link

oleksandrSydorenkoJ commented Aug 17, 2023 •
edited
Loading

Actual for skalenetwork/schain:3.17.0-beta.7

When consensus receives exitGracefully() call BEFORE proposing block 56693, it aborts this proposal and exit (at block 56693).

But consensus proposed 56693 and skaled creating 56694 block, and only after this block, consensus going to terminating.
No catching up during tests.
BFT = 12 seconds

graceful_exit_without_transactions.log

@github-project-automation github-project-automation bot moved this from QA to Ready For Pickup in SKALE Engineering 🚀 Aug 17, 2023
@kladkogex
Copy link
Contributor

kladkogex commented Aug 29, 2023 •
edited
Loading

Moving to 2.3 since it requires deep investigation and since it is not critical

@DmytroNazarenko DmytroNazarenko added this to the SKALE 2.3 milestone Aug 29, 2023
@PolinaKiporenko PolinaKiporenko modified the milestones: SKALE 2.3, SKALE 2.4 Nov 15, 2023
@PolinaKiporenko
Copy link

Moved to 2.4 as not critical for now

@PolinaKiporenko PolinaKiporenko moved this from Ready For Pickup to To Do in SKALE Engineering 🚀 Dec 15, 2023
@PolinaKiporenko PolinaKiporenko moved this from To Do to Ready For Pickup in SKALE Engineering 🚀 Jan 25, 2024
@kladkogex kladkogex modified the milestones: SKALE 2.4, SKALE 2.5 Mar 21, 2024
@kladkogex
Copy link
Contributor

Moving to 2.5 as we do not have time for it in 2.4

@PolinaKiporenko PolinaKiporenko modified the milestones: SKALE 2.5, SKALE 2.6 Apr 24, 2024
@PolinaKiporenko PolinaKiporenko moved this from Ready For Pickup to To Do in SKALE Engineering 🚀 Oct 10, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@kladkogex kladkogex

Labels
bug Something isn't working
Projects
SKALE Engineering 🚀
Status: No status
Milestone
SKALE 4.1
Development

Successfully merging a pull request may close this issue.

774 and 775 incorrect exit skalenetwork/skale-consensus
5 participants
@dimalit @kladkogex @DmytroNazarenko @oleksandrSydorenkoJ @PolinaKiporenko