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

Miner commitment is spent when 'Failed to submit Bitcoin transaction' #2356

Closed
MaksimalistT opened this issue Jan 17, 2021 · 12 comments
Closed

Miner commitment is spent when 'Failed to submit Bitcoin transaction' #2356

MaksimalistT opened this issue Jan 17, 2021 · 12 comments
Labels
locked mining

Comments

@MaksimalistT
Copy link

MaksimalistT commented Jan 17, 2021 •
edited
Loading

Describe the bug

miner commitment per block is spent
when errors like this occur:

ERRO [1610808785.386308] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:953] [relayer] Bitcoin RPC failure: transaction submission failed - Network("Bitcoin RPC: status(500) != success, body is 'Object({"error": Object({"code": Number(-25), "message": String("bad-txns-inputs-missingorspent")}), "id": String("stacks"), "result": Null})'")
WARN [1610808785.386393] [testnet/stacks-node/src/neon_node.rs:1638] [relayer] Failed to submit Bitcoin transaction

Steps To Reproduce
conf:
burn_fee_cap = 22000
satoshis_per_byte = 102

Expected behavior
miner commitment per block is NOT spent

Environment (please complete the following information):

  • OS: Amazon Linux
  • Rust version: rustc 1.49.0 (e1884a8e3 2020-12-29)
  • Version of the appropriate binary / software package: stacks-node 0.0.1 (master:7b83c6f22, release build, linux [x86_64])
@friedger
Copy link
Collaborator

friedger commented Jan 17, 2021 •
edited
Loading

The relevant btc tx are:
https://btc.com/2e0b6deca18dfb0ddbb389f3433db1bc33fcc18528007443f065bc2a1666c380 and
https://btc.com/5395f15af9735a81d597fc801741f6641fca5628939b6b7bb37457a5e9856928

and another one:
https://btc.com/f7b67cd177bf255f042d2b361c2c172805f4409230501cab2331e87394ed570c
https://btc.com/443db74ea0dc783547b43a568fc1a54376b6c2191fae6041cf9468057b5df535

@diwakergupta
Copy link
Member

@MaksimalistT @friedger can you also include debug logs from stacks-node when this happens?

@lgalabru @kantai would #2346 help with this?

@psq
Copy link
Contributor

psq commented Jan 18, 2021

I've also encountered this issue, and will dig out some logs as well.

@psq
Copy link
Contributor

psq commented Jan 18, 2021

After looking at the logs, I don't think anything gets spent when you get that error message, you see a transaction for that block because the miner has successfully sent other transactions. See attempt 7 below.

We should still fix this as the "best" commit was not successfully sent, but that's not always the last one where this happens.

INFO [1610788124.382293] [src/chainstate/stacks/miner.rs:829] [relayer] Miner: mined anchored block 4d9dfcad473604a459a769df998fc353139651ca1e3371c92d19378c258be369 with 2 txs, parent block 48e637fd1e02285d3d25773ee1b54c30d4fc1cf02acfa6aa34760871ff3f74b6, state root = 542e0d6dbc0f66e03af565e5b7840961175efa01065d2380b65dcba1c5153cab
INFO [1610788124.400016] [testnet/stacks-node/src/neon_node.rs:1574] [relayer] Succeeded assembling Stacks block #186: 4d9dfcad473604a459a769df998fc353139651ca1e3371c92d19378c258be369, with 2 txs, attempt 2
INFO [1610788124.463265] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:804] [relayer] Miner node: submitting leader_block_commit op for 4d9dfcad473604a459a769df998fc353139651ca1e3371c92d19378c258be369 - 03fb3bc5bae4c088ca38a8c68bfe741f3b1cb62a067b69917908089a2082af31ae, waiting for its inclusion in the next Bitcoin block

INFO [1610788195.984455] [src/chainstate/stacks/miner.rs:829] [relayer] Miner: mined anchored block 2e6f66f66e8be48bbb9c272262907a894f0b27c24150a9e88d31bf826f0198c6 with 2 txs, parent block 48e637fd1e02285d3d25773ee1b54c30d4fc1cf02acfa6aa34760871ff3f74b6, state root = 181b75158dcd38bdc57637dae2196be9059c7eb4f9d34a2b4e3f1f91bf38fff5
INFO [1610788195.996548] [testnet/stacks-node/src/neon_node.rs:1574] [relayer] Succeeded assembling Stacks block #186: 2e6f66f66e8be48bbb9c272262907a894f0b27c24150a9e88d31bf826f0198c6, with 2 txs, attempt 3
INFO [1610788195.996914] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:804] [relayer] Miner node: submitting leader_block_commit op for 2e6f66f66e8be48bbb9c272262907a894f0b27c24150a9e88d31bf826f0198c6 - 03fb3bc5bae4c088ca38a8c68bfe741f3b1cb62a067b69917908089a2082af31ae, waiting for its inclusion in the next Bitcoin block

INFO [1610788266.989116] [src/chainstate/stacks/miner.rs:829] [relayer] Miner: mined anchored block bb733c44b0a9d1fb78e30a537d9707958b9f2d079a31548184ac4536903650ca with 1 txs, parent block 48e637fd1e02285d3d25773ee1b54c30d4fc1cf02acfa6aa34760871ff3f74b6, state root = 181b75158dcd38bdc57637dae2196be9059c7eb4f9d34a2b4e3f1f91bf38fff5
INFO [1610788267.000101] [testnet/stacks-node/src/neon_node.rs:1574] [relayer] Succeeded assembling Stacks block #186: bb733c44b0a9d1fb78e30a537d9707958b9f2d079a31548184ac4536903650ca, with 1 txs, attempt 4
INFO [1610788267.000467] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:804] [relayer] Miner node: submitting leader_block_commit op for bb733c44b0a9d1fb78e30a537d9707958b9f2d079a31548184ac4536903650ca - 03fb3bc5bae4c088ca38a8c68bfe741f3b1cb62a067b69917908089a2082af31ae, waiting for its inclusion in the next Bitcoin block

INFO [1610788405.056671] [src/chainstate/stacks/miner.rs:829] [relayer] Miner: mined anchored block 5e7d46c7087fa86cfac693fc2974bae1bf3d232671ada763e649f4aec62d73f2 with 1 txs, parent block 48e637fd1e02285d3d25773ee1b54c30d4fc1cf02acfa6aa34760871ff3f74b6, state root = 5e31cbb1afc088f883b1fc532fcd3feab450ac0770095d26580aab48e2697312
INFO [1610788405.070524] [testnet/stacks-node/src/neon_node.rs:1574] [relayer] Succeeded assembling Stacks block #186: 5e7d46c7087fa86cfac693fc2974bae1bf3d232671ada763e649f4aec62d73f2, with 1 txs, attempt 5
INFO [1610788405.070898] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:804] [relayer] Miner node: submitting leader_block_commit op for 5e7d46c7087fa86cfac693fc2974bae1bf3d232671ada763e649f4aec62d73f2 - 03fb3bc5bae4c088ca38a8c68bfe741f3b1cb62a067b69917908089a2082af31ae, waiting for its inclusion in the next Bitcoin block

INFO [1610788475.911214] [src/chainstate/stacks/miner.rs:829] [relayer] Miner: mined anchored block c6ab47ed878366c6c54fbed458ddf9fa323ccd51ecfc09d5e36948c32d2b0f21 with 1 txs, parent block 48e637fd1e02285d3d25773ee1b54c30d4fc1cf02acfa6aa34760871ff3f74b6, state root = d96d07776686112861f55e9549b90def88c3d08c9baaa59701e290346f92cd9a
INFO [1610788475.924230] [testnet/stacks-node/src/neon_node.rs:1574] [relayer] Succeeded assembling Stacks block #186: c6ab47ed878366c6c54fbed458ddf9fa323ccd51ecfc09d5e36948c32d2b0f21, with 1 txs, attempt 6
INFO [1610788475.924661] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:804] [relayer] Miner node: submitting leader_block_commit op for c6ab47ed878366c6c54fbed458ddf9fa323ccd51ecfc09d5e36948c32d2b0f21 - 03fb3bc5bae4c088ca38a8c68bfe741f3b1cb62a067b69917908089a2082af31ae, waiting for its inclusion in the next Bitcoin block

INFO [1610788546.262044] [testnet/stacks-node/src/neon_node.rs:1574] [relayer] Succeeded assembling Stacks block #186: 9bfbe219ae8f330c69442792fe76cf39b24605fc4bd0118eebebb9adf4ac34df, with 2 txs, attempt 7
INFO [1610788546.262467] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:804] [relayer] Miner node: submitting leader_block_commit op for 9bfbe219ae8f330c69442792fe76cf39b24605fc4bd0118eebebb9adf4ac34df - 03fb3bc5bae4c088ca38a8c68bfe741f3b1cb62a067b69917908089a2082af31ae, waiting for its inclusion in the next Bitcoin block
ERRO [1610788546.298030] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:953] [relayer] Bitcoin RPC failure: transaction submission failed - Network("Bitcoin RPC: status(500) != success, body is \'Object({\"error\": Object({\"code\": Number(-25), \"message\": String(\"bad-txns-inputs-missingorspent\")}), \"id\": String(\"stacks\"), \"result\": Null})\'")
WARN [1610788546.298063] [testnet/stacks-node/src/neon_node.rs:1638] [relayer] Failed to submit Bitcoin transaction

@gzelda
Copy link

gzelda commented Jan 18, 2021 

INFO [1610946272.320900] [testnet/stacks-node/src/neon_node.rs:1592] [relayer] Succeeded assembling Stacks block #381: fc4a22ecffb644a29d7e2dbfc3e26d31f1708e2e486208c9cf625407a60aebd2, with 4 txs, attempt 11
INFO [1610946272.323043] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:827] [relayer] Miner node: submitting leader_block_commit op for fc4a22ecffb644a29d7e2dbfc3e26d31f1708e2e486208c9cf625407a60aebd2 - 02964a6d7758a04ce64a4d32c307ad1a1041f2186c2a0feaacdfe675ddf2496546, waiting for its inclusion in the next Bitcoin block
ERRO [1610946272.324593] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:976] [relayer] Bitcoin RPC failure: transaction submission failed - Network("Bitcoin RPC: status(500) != success, body is \'Object({\"error\": Object({\"code\": Number(-26), \"message\": String(\"insufficient fee, rejecting replacement 04873728f81d199b95ec2a52b9d36378054d1cb7ed107ae6608659f25aa7579a, not enough additional fees to relay; 0.0000035 < 0.00000351\")}), \"id\": String(\"stacks\"), \"result\": Null})\'")

Met code: -26 when attempt commit 11 times

@gzelda
Copy link

gzelda commented Jan 18, 2021

Here is the log after syncing the block.

DEBG [1610948793.522611] [testnet/stacks-node/src/run_loop/neon.rs:372] [main] Synchronized burnchain up to block height 666564 (chain tip height is 666564)
DEBG [1610948793.522632] [testnet/stacks-node/src/run_loop/neon.rs:380] [main] Synchronized full burnchain up to height 666564. Proceeding to mine blocks
DEBG [1610948793.522620] [testnet/stacks-node/src/neon_node.rs:769] [relayer] Relayer: Process tenure cad65aec07a7189477100bd05865c5266a1fd7fa/222cfbec07b66422b71b1bd00b51ea87728308adb760ba56a1bac0cdbd3f1d7b in 0000000000000000000da1aabb43f3b8abd601a683b9087892bdfc5d1757b939
WARN [1610948793.522745] [testnet/stacks-node/src/neon_node.rs:1181] [main] Skipped tenure because no active VRF key. Trying to register one.
DEBG [1610948793.522765] [testnet/stacks-node/src/run_loop/neon.rs:317] [main] Wait until we reach steady-state before processing more burnchain blocks...
DEBG [1610948793.522782] [testnet/stacks-node/src/syncctl.rs:389] [main] PoX watchdog in first reward cycle -- sync immediately
DEBG [1610948793.523105] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:1356] [relayer] BitcoinRPC builder: Some("daemontech2"):Some("daemontech2")@http://127.0.0.1:8332/
DEBG [1610948793.524258] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:910] [relayer] Payments value: 1397000, total_consumed: 1446580, total_spent: 49580, tx_fee: 44080, attempt: 1
DEBG [1610948793.524390] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:955] [relayer] Send transaction: "0100000001a939d54fa4607bf013dd6cf30db26ddde5eaa3aa7f5de20c1caaccbe515584bc030000006a4730440220237204607471132c22e93e7a348239cb336e3be3abfb1b287dd881bf8e42c451022045fbf2b9ade3748fed3210ac67d1858329d3de96d4c41f5b3f4229ea1a616250012102964a6d7758a04ce64a4d32c307ad1a1041f2186c2a0feaacdfe675ddf2496546fdffffff030000000000000000396a3758325ecad65aec07a7189477100bd05865c5266a1fd7fa3c34c3ef139e3fe4414cc1a86c1b19d06090c28d73d06d51d00d94c555ac31eb7c150000000000001976a91429b4f12c0c5acd2f389edfe83a5705673a34f72188ac08511500000000001976a91429b4f12c0c5acd2f389edfe83a5705673a34f72188ac00000000"
INFO [1610948793.524410] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:590] [relayer] Miner node: submitting leader_key_register op - 02964a6d7758a04ce64a4d32c307ad1a1041f2186c2a0feaacdfe675ddf2496546, waiting for its inclusion in the next Bitcoin block
DEBG [1610948793.524461] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:1356] [relayer] BitcoinRPC builder: Some("daemontech2"):Some("daemontech2")@http://127.0.0.1:8332/
ERRO [1610948793.525844] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:976] [relayer] Bitcoin RPC failure: transaction submission failed - Network("Bitcoin RPC: status(500) != success, body is \'Object({\"error\": Object({\"code\": Number(-25), \"message\": String(\"bad-txns-inputs-missingorspent\")}), \"id\": String(\"stacks\"), \"result\": Null})\'")

@psq
Copy link
Contributor

psq commented Jan 18, 2021 

INFO [1610946272.320900] [testnet/stacks-node/src/neon_node.rs:1592] [relayer] Succeeded assembling Stacks block #381: fc4a22ecffb644a29d7e2dbfc3e26d31f1708e2e486208c9cf625407a60aebd2, with 4 txs, attempt 11
INFO [1610946272.323043] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:827] [relayer] Miner node: submitting leader_block_commit op for fc4a22ecffb644a29d7e2dbfc3e26d31f1708e2e486208c9cf625407a60aebd2 - 02964a6d7758a04ce64a4d32c307ad1a1041f2186c2a0feaacdfe675ddf2496546, waiting for its inclusion in the next Bitcoin block
ERRO [1610946272.324593] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:976] [relayer] Bitcoin RPC failure: transaction submission failed - Network("Bitcoin RPC: status(500) != success, body is \'Object({\"error\": Object({\"code\": Number(-26), \"message\": String(\"insufficient fee, rejecting replacement 04873728f81d199b95ec2a52b9d36378054d1cb7ed107ae6608659f25aa7579a, not enough additional fees to relay; 0.0000035 < 0.00000351\")}), \"id\": String(\"stacks\"), \"result\": Null})\'")

Met code: -26 when attempt commit 11 times

this is not the same error, see #2347

@jcnelson
Copy link
Member

We believe that the cause of this issue is that there's a race condition between the miner's attempt to replace-by-fee, and the bitcoin chain advancing by one block before the miner sees the new chain tip. I think the code should just try mining again once the view of the bitcoin chain gets refreshed (and take this error as a hint to refresh the bitcoin chain tip).

@kantai kantai added miner and removed miner labels Jan 19, 2021
@jcnelson jcnelson removed the mining label Jan 19, 2021
@jcnelson jcnelson added miner and removed mining labels Jan 19, 2021
@kantai kantai removed the miner label Jan 19, 2021
@leslieonline27
Copy link

We believe that the cause of this issue is that there's a race condition between the miner's attempt to replace-by-fee, and the bitcoin chain advancing by one block before the miner sees the new chain tip. I think the code should just try mining again once the view of the bitcoin chain gets refreshed (and take this error as a hint to refresh the bitcoin chain tip).

I've managed to observe this in real-time - bitcoin chain advanced while my node was re-assembling the block and attempting a replace-by-fee when this error appeared. To confirm, there was no double spend although I may not have won as a result of the node not being able to submit its best commit and so the commit was essentially wasted

@lgalabru
Copy link
Contributor

Should be addressed with #2383

@lgalabru
Copy link
Contributor

lgalabru commented Feb 5, 2021

Addressed with https://github.com/blockstack/stacks-blockchain/releases/tag/2.0.3

@lgalabru lgalabru closed this as completed Feb 5, 2021
@blockstack-devops
Copy link
Contributor

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@stacks-network stacks-network locked as resolved and limited conversation to collaborators Nov 18, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
locked mining
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
10 participants
@psq @diwakergupta @lgalabru @jcnelson @kantai @friedger @gzelda @blockstack-devops @leslieonline27 @MaksimalistT