search

projectpai / paicoin

Official repo of PAI Coin
https://projectpai.com
MIT License
63 stars 35 forks source link

BIP 30 Error #377

Open pgerzani opened 3 years ago

pgerzani commented 3 years ago

While trying to address this chain stall we got the following odd error:

[2020-12-20 21:09:16.1675] [I] [pai1] [Bitcoin Job Manager] Block with hash: 00000000000fa163bfbe3a53b2b61867ecad1e4c69ae04350dafaa170589719b submitted...
[2020-12-20 21:09:16.1675] [W] [pai1] [Bitcoin Job Manager] Block 165961 submission failed with: bad-txns-BIP30

At the time there were like 12 tips at the same height. Could this be the source of this issue? I don't want to spend too much time investigating it in case it was a weird one-off scenario, but it would be good if we could rule out anything obvious.

sebastianrusu commented 3 years ago

This seems to be a side effect of the large number of tips at that height, since txid uniqueness is enforced by BIP30 and it is possible that the coins view contains the same transaction for multiple tips.

pgerzani commented 3 years ago

This issue arose again tonight. It seems like the validation logic does not like having a lot of tips, but there are a lot of tips due to a lack of votes currently. So, I got a few different errors. One with an initial chain stall and one with a subsequent one:

2021-02-08 19:11:36 UpdateTip: new best=0000000000114e0ff7585d6dbf0e2a9e58a7c1d437d59e6e3e2cc5b8b0c44790 height=172953 version=0xa0000000 log2_work=73.956896 tx=688353 date='2021-02-07 19:44:12' progress=0.999549 cache=0.5MiB(323txo)
2021-02-08 19:11:36 AddToWallet ea59a6d698b5e48530de92ffb71f72d6c58a102adebf15b7bca9ca120037bbf8
2021-02-08 19:11:36   - Load block from disk: 0.63ms [0.08s]
2021-02-08 19:11:36     - Sanity checks: 1.35ms [25.29s (1.39ms/blk)]
2021-02-08 19:11:36     - Fork checks: 0.99ms [66.75s (3.66ms/blk)]
2021-02-08 19:11:36 ERROR: ConnectBlock: Consensus::CheckTxInputs: babc20ba8ae24965f14509a666c69ebf6744209bd0f3c3926058232266e8441f, bad-txns-inputs-missingorspent, CheckTxInputs: inputs missing/spent (code 16)
2021-02-08 19:11:36 InvalidChainFound: invalid block=00000000004a28c208ffc360bff877267e091f1e417eeb401dbf843bdebe5b45  height=172954  log2_work=73.956896  date=2021-02-07 19:51:52
2021-02-08 19:11:36 InvalidChainFound:  current best=0000000000114e0ff7585d6dbf0e2a9e58a7c1d437d59e6e3e2cc5b8b0c44790  height=172953  log2_work=73.956896  date=2021-02-07 19:44:12
2021-02-08 19:11:36 ERROR: ConnectTip(): ConnectBlock 00000000004a28c208ffc360bff877267e091f1e417eeb401dbf843bdebe5b45 failed
2021-02-08 19:11:36 InvalidChainFound: invalid block=00000000004a28c208ffc360bff877267e091f1e417eeb401dbf843bdebe5b45  height=172954  log2_work=73.956896  date=2021-02-07 19:51:52
2021-02-08 19:11:36 InvalidChainFound:  current best=0000000000114e0ff7585d6dbf0e2a9e58a7c1d437d59e6e3e2cc5b8b0c44790  height=172953  log2_work=73.956896  date=2021-02-07 19:44:12
2021-02-08 19:11:37   - Load block from disk: 2.25ms [0.08s]

and then this:

2021-02-08 23:11:34 UpdateTip: new best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f height=172964 version=0xa0000000 log2_work=73.956896 tx=689770 date='2021-02-08 20:19:29' progress=0.999945 cache=2.1MiB(15144txo)
2021-02-08 23:11:34   - Load block from disk: 0.76ms [0.05s]
2021-02-08 23:11:34     - Sanity checks: 1.35ms [0.11s (1.36ms/blk)]
2021-02-08 23:11:34     - Fork checks: 1.00ms [0.15s (1.95ms/blk)]
2021-02-08 23:11:34 ERROR: ConnectBlock: Consensus::CheckTxInputs: 129a877379770e4ea2ebc701d67e2da43d2fcc51e291db1d55288badc47d5f92, bad-txns-inputs-missingorspent, CheckTxInputs: inputs missing/spent (code 16)
2021-02-08 23:11:34 InvalidChainFound: invalid block=00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166  height=172965  log2_work=73.956896  date=2021-02-08 20:58:20
2021-02-08 23:11:34 InvalidChainFound:  current best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f  height=172964  log2_work=73.956896  date=2021-02-08 20:19:29
2021-02-08 23:11:34 ERROR: ConnectTip(): ConnectBlock 00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166 failed
2021-02-08 23:11:34 InvalidChainFound: invalid block=00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166  height=172965  log2_work=73.956896  date=2021-02-08 20:58:20
2021-02-08 23:11:34 InvalidChainFound:  current best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f  height=172964  log2_work=73.956896  date=2021-02-08 20:19:29
2021-02-08 23:11:35   - Load block from disk: 0.79ms [0.05s]

and this one:

2021-02-09 01:08:27 UpdateTip: new best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f height=172964 version=0xa0000000 log2_work=73.956896 tx=689770 date='2021-02-08 20:19:29' progress=0.999908 cache=2.1MiB(15146txo)
2021-02-09 01:08:27   - Load block from disk: 0.89ms [0.06s]
2021-02-09 01:08:27     - Sanity checks: 1.34ms [0.11s (1.36ms/blk)]
2021-02-09 01:08:27     - Fork checks: 1.03ms [0.16s (1.91ms/blk)]
2021-02-09 01:08:27 ERROR: ConnectBlock: Consensus::CheckTxInputs: 129a877379770e4ea2ebc701d67e2da43d2fcc51e291db1d55288badc47d5f92, bad-txns-inputs-missingorspent, CheckTxInputs: inputs missing/spent (code 16)
2021-02-09 01:08:27 InvalidChainFound: invalid block=00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166  height=172965  log2_work=73.956896  date=2021-02-08 20:58:20
2021-02-09 01:08:27 InvalidChainFound:  current best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f  height=172964  log2_work=73.956896  date=2021-02-08 20:19:29
2021-02-09 01:08:27 ERROR: ConnectTip(): ConnectBlock 00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166 failed
2021-02-09 01:08:27 InvalidChainFound: invalid block=00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166  height=172965  log2_work=73.956896  date=2021-02-08 20:58:20
2021-02-09 01:08:27 InvalidChainFound:  current best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f  height=172964  log2_work=73.956896  date=2021-02-08 20:19:29
2021-02-09 01:08:27   - Load block from disk: 0.77ms [0.06s]
2021-02-09 01:08:27     - Sanity checks: 1.43ms [0.11s (1.36ms/blk)]
2021-02-09 01:08:27     - Fork checks: 1.05ms [0.16s (1.90ms/blk)]
2021-02-09 03:43:58 UpdateTip: new best=000000000081d9b317e30360dc49abc20f89b89ac6bd6fe9b1d2c8475a7728a5 height=172965 version=0xa0000000 log2_work=73.956896 tx=689806 date='2021-02-09 02:33:57' progress=0.999978 cache=0.0MiB(220txo)
2021-02-09 03:43:58   - Connect postprocess: 1.40ms [0.05s (0.31ms/blk)]
2021-02-09 03:43:58 - Connect block: 12.27ms [0.40s (2.40ms/blk)]
2021-02-09 03:43:58   - Load block from disk: 0.00ms [0.03s]
2021-02-09 03:43:58     - Sanity checks: 0.00ms [0.19s (1.11ms/blk)]
2021-02-09 03:43:58 ERROR: ConnectBlock(): tried to overwrite transaction
2021-02-09 03:43:58 InvalidChainFound: invalid block=0000000000391f27ca25f17162912cb7fe41164ae57fd2ae852008ea6dab236d  height=172966  log2_work=73.956896  date=2021-02-09 03:43:57
2021-02-09 03:43:58 InvalidChainFound:  current best=000000000081d9b317e30360dc49abc20f89b89ac6bd6fe9b1d2c8475a7728a5  height=172965  log2_work=73.956896  date=2021-02-09 02:33:57
2021-02-09 03:43:58 ERROR: ConnectTip(): ConnectBlock 0000000000391f27ca25f17162912cb7fe41164ae57fd2ae852008ea6dab236d failed
2021-02-09 03:43:58 InvalidChainFound: invalid block=000000000081d9b317e30360dc49abc20f89b89ac6bd6fe9b1d2c8475a7728a5  height=172965  log2_work=73.956896  date=2021-02-09 02:33:57
2021-02-09 03:43:58 InvalidChainFound:  current best=000000000081d9b317e30360dc49abc20f89b89ac6bd6fe9b1d2c8475a7728a5  height=172965  log2_work=73.956896  date=2021-02-09 02:33:57
2021-02-09 03:43:58 AddToWallet 68b72a41ac5e53c8b454372eb61ab36dd2553adfb0feb35ae16952fb30acd32d
2021-02-09 03:43:58 sending ping (8 bytes) peer=15

What is particularly odd, is I have seen a few times where the result from getblocktemplate is based on a block that doesn't show up in the chain tips list and then when a block is submitted with it, predictably results in bad-prev-blk error. I don't know why it would do that given both operations use the same GetChainTips() call.

It seems like there is a shortage of votes currently, so that combined with the validation issues with a lot of concurrent tips seems to have resulted in 2 long chain stalls over the last 2 days.

pgerzani commented 3 years ago

Also got these:

2021-02-09 04:09:26 ERROR: AcceptBlock: bad-cb-height, block height mismatch in coinbase (code 16)
2021-02-09 04:09:26 ERROR: ProcessNewBlock: AcceptBlock FAILED (block height mismatch in coinbase)
2021-02-09 04:09:26 ThreadRPCServer method=getblock
2021-02-09 04:09:27 sending ping (8 bytes) peer=5
2021-02-09 04:09:27 received: pong (8 bytes) peer=5
2021-02-09 04:09:27 received: ping (8 bytes) peer=5
2021-02-09 04:09:27 sending pong (8 bytes) peer=5
2021-02-09 04:09:27 Received a POST request for / from 127.0.0.1:49826
2021-02-09 04:09:27 ThreadRPCServer method=getblocktemplate
2021-02-09 04:09:27 Checking chain tip 0000000000478561d6108b70e9bc11bb2f3c3574430fef8145b87598a80e7d96 with votes: 0...
2021-02-09 04:09:27 Checking chain tip 0000000000391f27ca25f17162912cb7fe41164ae57fd2ae852008ea6dab236d with votes: 0...
2021-02-09 04:12:37 submitted block hash 00000000004833c3925eb2a5e4f0e63f5f1e2557b858e7b70068742226439b09
2021-02-09 04:12:37 ERROR: AcceptBlock: bad-cb-height, block height mismatch in coinbase (code 16)
2021-02-09 04:12:37 ERROR: ProcessNewBlock: AcceptBlock FAILED (block height mismatch in coinbase)
2021-02-09 04:12:37 ThreadRPCServer method=getblock
2021-02-09 04:12:37 Received a POST request for / from 127.0.0.1:51278
2021-02-09 04:12:37 ThreadRPCServer method=getblocktemplate
2021-02-09 04:12:37 Checking chain tip 0000000000478561d6108b70e9bc11bb2f3c3574430fef8145b87598a80e7d96 with votes: 0...
2021-02-09 04:12:37
2021-02-09 04:14:40 UpdateTip: new best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f height=172964 version=0xa0000000 log2_work=73.956896 tx=689770 date='2021-02-08 20:19:29' progress=0.999848 cache=0.0MiB(205txo)
2021-02-09 04:14:40   - Load block from disk: 0.71ms [0.01s]
2021-02-09 04:14:40     - Sanity checks: 1.33ms [0.03s (1.33ms/blk)]
2021-02-09 04:14:40     - Fork checks: 0.80ms [0.02s (0.90ms/blk)]
2021-02-09 04:14:40 ERROR: ConnectBlock: Consensus::CheckTxInputs: 129a877379770e4ea2ebc701d67e2da43d2fcc51e291db1d55288badc47d5f92, bad-txns-inputs-missingorspent, CheckTxInputs: inputs missing/spent (code 16)
2021-02-09 04:14:40 InvalidChainFound: invalid block=00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166  height=172965  log2_work=73.956896  date=2021-02-08 20:58:20
2021-02-09 04:14:40 InvalidChainFound:  current best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f  height=172964  log2_work=73.956896  date=2021-02-08 20:19:29
2021-02-09 04:14:40 ERROR: ConnectTip(): ConnectBlock 00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166 failed
2021-02-09 04:14:40 InvalidChainFound: invalid block=00000000005ddc31b56cd10040311d47a5427380551e983cae4a62c0cb093166  height=172965  log2_work=73.956896  date=2021-02-08 20:58:20
2021-02-09 04:14:40 InvalidChainFound:  current best=00000000003142b609bfc577500dd5ef292cf3c7a172a1274655dc47d2854c2f  height=172964  log2_work=73.956896  date=2021-02-08 20:19:29
2021-02-09 04:14:40   - Load block from disk: 0.77ms [0.01s]
2021-02-09 04:14:40     - Sanity checks: 1.40ms [0.03s (1.33ms/blk)]
2021-02-09 04:14:40     - Fork checks: 0.62ms [0.02s (0.88ms/blk)]
pgerzani commented 3 years ago

Also got this one just now:

2021-02-09 06:28:50 Received a POST request for / from 127.0.0.1:53472
2021-02-09 06:28:50 ThreadRPCServer method=submitblock
2021-02-09 06:28:50 submitted block hash 000000000042fdeb04aceeafee0d027166f18a414373cdb53e7fb75ba3c884b5
2021-02-09 06:28:50 ERROR: AcceptBlock: bad-cb-height, block height mismatch in coinbase (code 16)
2021-02-09 06:28:50 ERROR: ProcessNewBlock: AcceptBlock FAILED (block height mismatch in coinbase)
2021-02-09 06:28:50 ThreadRPCServer method=getblock

This was submitted by our miningcore instance to itself, so not sure how the encoding would be wrong?