dominant-strategies / go-quai

Official Go Implementation of the Quai Network
GNU General Public License v3.0
2.37k stars 460 forks source link

[Core] Identify and fix issues with excessive append times in ProgPow #1914

Closed Djadih closed 3 months ago

Djadih commented 3 months ago
20300:INFO   [06-21|01:33:51.520] Appended new block                        difficulty=500 elapsed=712.997ms etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0x6c0b99a7062a1f37327f1230cfb8bf916a1c409e20ae191e434545e7290fe202 inboundEtxs from dom=0 intrinsicS=1 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[93 350 4270]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0x13b92e1355213cd90fde247f117e78de668cc14438a3f28a7bfb627250c7da1b
20322:INFO   [06-21|01:34:01.551] Appended new block                        difficulty=500 elapsed=172.961ms etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0x2126404fa2c03c7ec30d0cbe1186ecaf11d8b1e77d2df9f6ff0a6a546a40e55e inboundEtxs from dom=0 intrinsicS=2 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[93 351 4275]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0x6b1494100922cfad8c10c9ccc54144d08da782585dc6e1e02c5caf10651ab2eb
20347:INFO   [06-21|01:34:32.327] Appended new block                        difficulty=500 elapsed=629.403ms etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0x1fb5df9a465cc0e36be8892457a98b9355e8a535ab654d2054df21790cfb4e45 inboundEtxs from dom=0 intrinsicS=3 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[93 352 4281]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0x15b895bfd58a235892c2b1f67b1e1d4ee778e1df7c2d0659aa33c83c25791fb6
20370:INFO   [06-21|01:34:49.848] Appended new block                        difficulty=500 elapsed=468.404ms etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0x92c66b6ab5d09e99c80c2516b52739513fe8c10d0cf1f718351d5bff3e25f810 inboundEtxs from dom=0 intrinsicS=0 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[93 353 4287]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0xabbc9b7abf8a39611e4b75d990156c1d0c48374c454bb3925fee6c2d27a64f27
20394:INFO   [06-21|01:35:27.619] Appended new block                        difficulty=500 elapsed=789.926ms etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0xff033ac7186fdf36ccda4a6f0f8120e15147cf08b888796c5878fcd5aedc25fb inboundEtxs from dom=0 intrinsicS=0 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[93 354 4293]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0xaef1b97c40c897c8da296f0ee187a62b280d30183e5dd2da2447db86370f7a75
20437:INFO   [06-21|01:37:14.904] Appended new block                        difficulty=500 elapsed=230.867ms etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0x9eff297682f9ec76c3a3a42ea28df1de698eb41202147bb55c282f6aff244b98 inboundEtxs from dom=0 intrinsicS=0 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[93 355 4317]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0xd028adbb317ba7d0622bf29b055111d8fadc388a5b2057435fa1fdd5826f1dbe
20921:INFO   [06-21|08:24:35.834] Appended new block                        difficulty=500 elapsed=1m41.664s etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0xe1fd746416bcc7edc24722c520d8bdb2f4db03f9409353d56ca0a0d9d07c6a07 inboundEtxs from dom=0 intrinsicS=0 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[107 356 4339]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0x0c9a817059db627009782acfce58efa0bfceaddf1502663338cb90b3657c5aed
21288:INFO   [06-21|13:43:51.559] Appended new block                        difficulty=500 elapsed=1m46.016s etxSetRoot=0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421 etxs emitted=0 etxs inbound=0 evmRoot=0x4269b376b84bedba74829e1896ff81d822c8e37752cdfeee1e4ff5277de0b092 gas=0 gasLimit=160000000 hash=0x44c95873fbf6a8ad6f76301153b5c134c744175f1a09fb4a9385ec820836663a inboundEtxs from dom=0 intrinsicS=1 iworkShare=0 location="[0 0]" net outputs-inputs=0 number="[107 357 4358]" order=1 qiTxs=0 quaiTxs=0 totalTxs=0 uncles=0 utxoRoot=0x8711c9f24d973f28dd745d0dd3c150fc05a6fd2fd0bf50a201fa7cd9555e8479

Something has regressed with ProgPow causing append times to stretch into the minutes range. This is breaking everything from pendingheaders to epoch coordination.

Djadih commented 3 months ago

Fix implemented

Number of blocks appended: 362 Average elapsed time: 39.292 ms Standard deviation: 27.410 ms