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

[TESTNET BUG] Some miners only mine every other blocks #1783

Closed
psq opened this issue Aug 1, 2020 · 6 comments
Closed

[TESTNET BUG] Some miners only mine every other blocks #1783

psq opened this issue Aug 1, 2020 · 6 comments
Labels
bug Unwanted or unintended property causing functional harm testnet

Comments

@psq
Copy link
Contributor

psq commented Aug 1, 2020

While analyzing the blocks produced by the miners, I noticed that some miners were mining only every other block. For example, with the help of Discord, we have identified the miners from from phillip and @friedger were behaving that way. My miner has not exhibited this behavior, and this is still not clear to me why only some would behave that way (maybe the fact that they are both on different continents may be a factor...).

From the logs (from @friedger, but the logs from phillip look similar), we see the following (excerpt with the relevant bits around the start of each new block):

# 1
DEBUG [1596103298.523] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
INFO [1596103299.118] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:328] [ThreadId(6)] Miner node: submitting leader_key_register op - 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34
DEBUG [1596103299.119] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/

# 2
DEBUG [1596103325.109] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
INFO [1596103325.704] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:378] [ThreadId(6)] Miner node: submitting leader_block_commit op - 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34
DEBUG [1596103325.705] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103325.921] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103326.330] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103327.546] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103327.927] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:392] [ThreadId(6)] No UTXOs for 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34

# 3
DEBUG [1596103356.573] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
INFO [1596103357.197] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:328] [ThreadId(6)] Miner node: submitting leader_key_register op - 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34
DEBUG [1596103357.199] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/

# 4
DEBUG [1596103388.862] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
INFO [1596103389.455] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:378] [ThreadId(6)] Miner node: submitting leader_block_commit op - 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34
DEBUG [1596103389.456] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103389.670] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103390.051] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103396.134] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103396.501] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:392] [ThreadId(6)] No UTXOs for 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34

# 5
DEBUG [1596103417.861] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
INFO [1596103418.463] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:328] [ThreadId(6)] Miner node: submitting leader_key_register op - 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34
DEBUG [1596103418.464] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/

# 6
DEBUG [1596103445.135] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
INFO [1596103445.759] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:378] [ThreadId(6)] Miner node: submitting leader_block_commit op - 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34
DEBUG [1596103445.760] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103445.986] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103446.376] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103452.218] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103452.602] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:392] [ThreadId(6)] No UTXOs for 03aefb4c3b0584fa

In #1 the miner registers a key. So far, so good

In #2, there was a key registered, so the node will commit a block:

DEBUG [1596103325.109] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
INFO [1596103325.704] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:378] [ThreadId(6)] Miner node: submitting leader_block_commit op - 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34
DEBUG [1596103325.705] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/

the 2 calls to BitcoinRPC builder should be listunspent and sendrawtransaction

Then the miners tries to register a key for next block:

DEBUG [1596103325.921] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103326.330] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103327.546] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596103327.927] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:392] [ThreadId(6)] No UTXOs for 03aefb4c3b0584fae094e64c6903f81cac9355868542e8af0eb72919d513a5aa34

but this fails because the node could not find UTXOs (spoiler alert, there are still some!). The 3 calls to BitcoinRPC builder should be respectively listunspent, importaddress, and listunspent (from https://github.com/blockstack/stacks-blockchain/blob/master/testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs#L206). Note that the the 3 calls can take up to 6-7 seconds (not visible in #2, but check #6).

So the above seems to explain why the node only mines every other blocks as the leader key registration fails every other time.

But now the question is: why do the UTXOs disappear?

My best theory so far is that spending some UTXOs for the commit transaction forces a rescan on the bitcoin node (an other possibility is that the utxos get kicked out of the cache), and even though get_utxos uses a sleep(1000) before the second call to listunspent, this does not seem to be enough, but 30 seconds later, when it is time to register a new key, the rescan has completed, and the node will find utxos.

Now one reason why the the rescan takes so long is that there are a lot of them after a miner has been mining for a while. In the case of @friedger when I queried the argon bitcoin node, there were about 3,400 and counting. Here are a few:

    {
      "txid": "b3906443a1795cfa6228325525d086287b6e42c2c82e249daebe73d1e3820100",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 6909,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "247c1fde898bbaabcfd143bdfe4c4d847248aa57f8fd47243d20f1e350a40200",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 1622,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "c760e0dfe8ea58f6200dea3edb9d7cd0fc32644e1b1c702b650f50b4969d0400",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 10701,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "1353dca0ae6c32b0a130e3931252495cc864255b75984b63758fa8a8b4560600",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 10045,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "229ac48eb5d4830c5fd806d01a078965b5f4933e44d5f751a36bab95b20e0e00",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 7282,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "712add5f6986a4663fd67f985243cdab2caedce4e7062432a01482517af61500",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 9808,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "93fa19f2b00d95fe9ead9f4f3b354b301262b22e81868c1b770812b404152b00",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 6705,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "4a702bc5345073158197e7e05da3adff5b5c6f3f198623390bc5c5cbb8084700",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 2363,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "d522fdb486114cc9a6e725858aa137e6d235cb01da3cf396aad94da4c5e75a00",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 2654,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "6278964194504d6b91dcd82786c6833d2598b3f58f2c67cc6464e5e7d4fd6300",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 1510,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "0e0419f29b7b06a52cb89fc15b905cd4a27cd726e8405f02ccb1347114466400",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 3886,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "4643f06b7ba57319908a046ec00607c860f8f8ffcc3a829ed0b95c1d1e907000",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 3725,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "c2cb2ea5b69f868728860bace9e466daaad6f0c5e5d6b5b8d46b4653618e8600",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 1574,
      "spendable": false,
      "solvable": false,
      "safe": true
    },
    {
      "txid": "49a8b7e20151c50a230871fdfc0e33133f2ccdba91a8ff74f98d92d75e028700",
      "vout": 1,
      "address": "mmoSjCkyJFMRPPf9xriVbTAWF9jmALqekD",
      "label": "",
      "scriptPubKey": "76a91444ef2530c93d3b0196131fc365d6e5c4c86f1c9988ac",
      "amount": 0.00005500,
      "confirmations": 9410,
      "spendable": false,
      "solvable": false,
      "safe": true
    },

Only 1 of them meets the requirement (> 11000 sat). My current thinking is that the miner's code should more judiciously reuse small utxos (created by the key registration transaction) instead of looking for the first utxo with sufficient balance (https://github.com/blockstack/stacks-blockchain/blob/master/testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs#L860).

One possibility might be to use the amount the node plans to burn on the next round for the tx amount rather than 5500 so that utxo can be reused, or transfer the whole utxo amount minus the fee (no change output required means smaller transaction)) to avoid creating all these tiny utxos.

I would not suggest combining more than 1 input to meet the amount required, this would make the transaction bigger.

If my theory is close to correct, the fix should be fairly simple...
@jcnelson
Copy link
Member

jcnelson commented Aug 1, 2020

Thank you so much for taking a deep look at this @psq @friedger!

Fundamentally, the reason why a LeaderKeyRegisterOp Bitcoin transaction creates a UTXO with 5500 sats is because it needs to register a Bitcoin address with the Stacks node that will be paired with a corresponding LeaderBlockCommitOp. The LeaderBlockCommitOp "consumes" an associated LeaderKeyRegisterOp in that one of its inputs must have a scriptSig that matches the second scriptPubKey output of the LeaderKeyRegisterOp (i.e. the first non-OP_RETURN output). This check ensures that the principal who can use the VRF public key to produce a VRF proof and VRF seed as part of a block-commit can only have been the same principal who registered the VRF public key in the first place. But, implementing this check currently creates a "dust" UTXO output each time a VRF public key is registered, leading to this problem.

There's a couple ways I think we could fix this:

  • Make the Bitcoin UTXO scanner remember the UTXOs it creates. Then, when it goes to produce a new Bitcoin transaction, it will try to reuse a known UTXO instead of ask the Bitcoin node to re-scan each time.
  • Implement Burnchain: Allow VRF public key reuse #1615, so a miner only needs to register a single VRF public key to mine multiple blocks. Moreover, Burnchain: Allow VRF public key reuse #1615 would drop the requirement that a LeaderBlockCommitOp's first scriptSig needs to be paired with the LeaderKeyRegisterOp's scriptPubKey, since only the principal who possesses the VRF private key can generate a valid Stacks block in the first place. This would remove the need to create the dust UTXOs on LeaderKeyRegisterOps in the first place.

Related, I welcome any thoughts and opinions on #1615. It's a consensus-breaking change.

@paradigma-cl
Copy link

@psq @jcnelson Here in Github I am (Phillip) called @paradigma-cl . I am glad that our remote mining nodes can serve for testing! I will put a couple more in operation, to help to create more massivity of nodes mining.

@psq
Copy link
Contributor Author

psq commented Aug 1, 2020

Make the Bitcoin UTXO scanner remember the UTXOs it creates. Then, when it goes to produce a new Bitcoin transaction, it will try to reuse a known UTXO instead of ask the Bitcoin node to re-scan each time

one can assume that a miner would use an address exclusively for mining, so yes, you probably wouldn't need to re-query the bitcoin node for available UTXOs as often, or just during startup, and instead make it a requirement. Furthermore, even if you can't keep reusing the same UTXO back to back to register a new key, 2 should be enough, and you could keep switching between the 2 (register UTXO1, commit with UTXO1/register using UTXO2, commit with UTXO2/register using UTXO1, commit with UTXO1/register using UTXO2...), which would keep the number of UTXOs needed to a minimum.

The JSON reply for listunspent in @friedger case was well over 1MB!

from #1615: since only the principal who has the VRF private key can produce a valid Stacks block

Intuitively, I had a feeling that this statement would apply, removing the need for registering a new key for each block, and glad to see it expressed in #1615 (I had not read it previously).

I will mull over #1615, as this would certainly help reduce the amount of fees for each block, and cut down on network usage. In fact, I think this is a must, as this would shave off about 40% of the bitcoin fee per block.

@psq
Copy link
Contributor Author

psq commented Aug 1, 2020

I am (Phillip) called @paradigma-cl

good to know, @paradigma-cl, as I almost unknowingly spammed an unsuspecting @ phillip on github, and thank you for your help!

@timstackblock timstackblock added testnet bug Unwanted or unintended property causing functional harm and removed bug Unwanted or unintended property causing functional harm labels Aug 5, 2020
@timstackblock timstackblock changed the title Some miners only mine every other blocks [TESTNET BUG] Some miners only mine every other blocks Aug 5, 2020
@psq psq mentioned this issue Aug 7, 2020
Closed
9 tasks
@diwakergupta
Copy link
Member

@psq can you verify if this is still an issue after your fix for #1615 and close or update as appropriate?

@psq
Copy link
Contributor Author

psq commented Sep 18, 2020

@diwakergupta this can't happen anymore because once a key is registered, there's always going to be a key available to send a commit.

@psq psq closed this as completed Sep 18, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Unwanted or unintended property causing functional harm testnet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@psq @diwakergupta @jcnelson @paradigma-cl @timstackblock