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.

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

[TESTNET BUG] Mining running but stops paying BTC #1797

Closed
9 tasks
paradigma-cl opened this issue Aug 7, 2020 · 16 comments
Closed
9 tasks

[TESTNET BUG] Mining running but stops paying BTC #1797

paradigma-cl opened this issue Aug 7, 2020 · 16 comments
Assignees
Labels
bug Unwanted or unintended property causing functional harm testnet

Comments

@paradigma-cl
Copy link

Describe the bug

Detected that the BTC balance has stopped decreasing at the value {"balance":0.22142} for address /btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo . It has stayed in that value for several hours. The mining node looks like normal execution.

Steps To Reproduce

Running the mining node

Expected behavior

The BTC balance should continue to decrease as it have been several days.

Environment

  • OS: Ubuntu
  • Rust version cargo 1.43.0 (2cbe9048e 2020-05-03)
  • Output of stacks-node version stacks-node 0.1.0 => 23.0.0.0 (master:afc748aa1, release build, linux [x86_64])

Additional context

Please include any relevant stack traces, error messages and logs.

If you are encountering an issue with a smart contract, please include the smart contract code
that demonstrates the issue.


If you think this is eligible for a bug bounty, please check the relevant boxes below:

Critical, Launch Blocking Bugs

Consensus critical bugs

  • Can cause a chain split
  • Can cause an invalid transaction to get mined
  • Can cause an invalid block to get accepted
  • [ x] Can cause a node to stall

State corruption

  • Can modify a smart contract’s data maps and data vars without a `contract-call?

Stolen funds

  • Any address losing STX without a corresponding transfer
  • Modify token balances and NFT ownership in other contracts without a contract-call?

Take control and/or bring network to a halt

  • [x ] Take control and/or bring network to a halt

Major, Launch Blocking Bugs

Major bugs

  • Performance or correctness bugs that don’t rise to P0 level
  • [x ] Stress test or DoS attacks that slow things down enough
  • Resource exhaustion
  • [ x] Expected functionality doesn’t work in obvious ways (important to be super specific with this wording)

Minor, Non-launch blocking bugs

Minor bugs

  • Bugs in non-critical software (CLI, UI, etc) that doesn’t impact critical functionality
    logs_last10k.log.gz
@paradigma-cl paradigma-cl added bug Unwanted or unintended property causing functional harm testnet labels Aug 7, 2020
@psq
Copy link
Contributor

psq commented Aug 7, 2020

@paradigma-cl the thread that usually runs the miner [ThreadId(6)] is not in the log portion you included, so it either died, or more likely stalled on some i/o call. Do you have logs that go farther back that the 15+ minutes you included. Look for the last occurrences of [ThreadId(6)].

You still have 1 spendable UTXO (1_732_500 sats), but the rest, about 0.2 BTC (20_000_000 sats) of what you have is no longer usable (related to #1783)

@paradigma-cl
Copy link
Author

@psq Here is the last log of thread(6)
DEBUG [1596603672.840] [src/net/download.rs:1312] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Advance downloader to start at sortition heights 17778,16385
DEBUG [1596603672.840] [src/net/download.rs:1317] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Downloader for blocks has reached the chain tip
DEBUG [1596603672.840] [src/net/download.rs:1331] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Downloader for microblocks has reached the chain tip
DEBUG [1596603672.840] [src/net/download.rs:1349] [ThreadId(7)] Did a full pass over the burn chain sortitions and found no new data
DEBUG [1596603672.840] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603672.840] [src/net/neighbors.rs:2022] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk state is HandshakeFinish
DEBUG [1596603672.840] [src/net/chat.rs:1200] [ThreadId(7)] convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): sent 0 bytes
DEBUG [1596603672.840] [src/net/neighbors.rs:2117] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk has taken 6 steps (total of 0 walks)
DEBUG [1596603672.840] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603672.889] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603672.891] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 5000) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603673.889] [src/chainstate/burn/db/sortdb.rs:1072] [ThreadId(1)] Connect/Open sortdb '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/data.db' as 'readwrite', with index as '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf'
DEBUG [1596603673.890] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(1)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf;
DEBUG [1596603673.953] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603673.954] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 1 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13666-13667
DEBUG [1596603673.956] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13667, so will not validate continuity
DEBUG [1596603673.956] [src/burnchains/bitcoin/spv.rs:559] [ThreadId(1)] No header for parent block 13665, so will not validate continuity
DEBUG [1596603673.956] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 1 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13667
DEBUG [1596603673.966] [src/burnchains/bitcoin/indexer.rs:509] [ThreadId(1)] Search for reorg'ed Bitcoin headers from 13667 - 13683
DEBUG [1596603673.966] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603674.100] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603674.100] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=18134275822611385884) to 35.221.35.47:18444
DEBUG [1596603674.260] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603674.260] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603674.277] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603674.277] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603674.277] [src/burnchains/bitcoin/spv.rs:660] [ThreadId(1)] Get headers 13667-13682 to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603674.277] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 112fac265dfa98b0ac8fea0e6625cc8fbf6f640f37d1058462f398c14b72afc6 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603674.409] [src/burnchains/bitcoin/network.rs:297] [ThreadId(1)] Handle ping 14650116816717465724
DEBUG [1596603674.409] [src/burnchains/bitcoin/network.rs:300] [ThreadId(1)] Send pong 14650116816717465724
DEBUG [1596603674.531] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 15 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13667-13682
DEBUG [1596603674.532] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13682, so will not validate continuity
DEBUG [1596603674.532] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 15 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13668
DEBUG [1596603674.549] [src/burnchains/bitcoin/spv.rs:271] [ThreadId(1)] Validate PoW between blocks 14112-16128
DEBUG [1596603674.549] [src/burnchains/bitcoin/spv.rs:451] [ThreadId(1)] Handled 15 Headers: 380b29a8633ba0102186031df972ce7c925004e359b7be9684dba3eaf880f6ce-708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603674.549] [src/burnchains/bitcoin/spv.rs:701] [ThreadId(1)] Request headers for blocks 13682 - 15682 in range 13667 - 13682
DEBUG [1596603674.549] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba for 2000 headers to 35.221.35.47:18444
DEBUG [1596603674.941] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(1)] Message handler indicates to stop
DEBUG [1596603674.941] [src/burnchains/bitcoin/indexer.rs:572] [ThreadId(1)] Found common Bitcoin block ancestor at height 13682: BlockHeader { version: 536870912, prev_blockhash: d75f3e9a7f20ff3a3123ebd7d56ed911212c1be0a959a9b2fbab9f9849bec103, merkle_root: 8012ebd1f17b32b5d2da3ec5d6c6ababd3675950a4d9f5fa765890cc7c9bcc14, time: 1596603665, bits: 545259519, nonce: 6 }
DEBUG [1596603674.941] [src/burnchains/bitcoin/indexer.rs:596] [ThreadId(1)] Bitcoin headers history is consistent up to 13682
DEBUG [1596603674.942] [src/burnchains/burnchain.rs:687] [ThreadId(1)] Sync headers from 13682
DEBUG [1596603674.942] [src/burnchains/bitcoin/indexer.rs:458] [ThreadId(1)] Sync all headers starting at block 13682
DEBUG [1596603674.953] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat
DEBUG [1596603674.953] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603675.093] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603675.093] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=18134275822611385884) to 35.221.35.47:18444
DEBUG [1596603675.239] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603675.239] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603675.239] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603675.239] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603675.239] [src/burnchains/bitcoin/spv.rs:656] [ThreadId(1)] Have all headers up to 13682
DEBUG [1596603675.239] [src/burnchains/bitcoin/indexer.rs:394] [ThreadId(1)] begin_session() terminates conversation
DEBUG [1596603675.239] [src/burnchains/burnchain.rs:698] [ThreadId(1)] Sync'ed headers from 13682 to 13682. DB at 13682
DEBUG [1596603675.240] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:202] [ThreadId(1)] Done receiving blocks
DEBUG [1596603677.924] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603677.926] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603679
DEBUG [1596603677.927] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603677.927] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603679
DEBUG [1596603677.927] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603677.927] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvBegin
DEBUG [1596603677.927] [src/net/inv.rs:953] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): skip convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): not authenticated
DEBUG [1596603677.927] [src/net/inv.rs:981] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Will send 0 getblocksinv requests (out of 1 active events)
DEBUG [1596603677.927] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvFinish
DEBUG [1596603677.927] [src/net/inv.rs:772] [ThreadId(7)] Still waiting for 0 blocksinv replies
DEBUG [1596603677.927] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is Done
DEBUG [1596603677.927] [src/net/inv.rs:1189] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Inv-sync finished with all (0) up-to-date neighbors (13682 sortitions); restarting scan with 0 peers
DEBUG [1596603677.927] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603677.927] [src/net/download.rs:1399] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle block downloads until 1596603732
DEBUG [1596603677.927] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603677.927] [src/net/neighbors.rs:2022] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk state is HandshakeFinish
DEBUG [1596603677.927] [src/net/chat.rs:1200] [ThreadId(7)] convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): sent 0 bytes
DEBUG [1596603677.927] [src/net/neighbors.rs:2117] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk has taken 7 steps (total of 0 walks)
DEBUG [1596603677.927] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603677.976] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603677.977] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 5000) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603680.241] [src/chainstate/burn/db/sortdb.rs:1072] [ThreadId(1)] Connect/Open sortdb '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/data.db' as 'readwrite', with index as '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf'
DEBUG [1596603680.241] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(1)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf;
DEBUG [1596603680.302] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603680.304] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 1 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13666-13667
DEBUG [1596603680.305] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13667, so will not validate continuity
DEBUG [1596603680.305] [src/burnchains/bitcoin/spv.rs:559] [ThreadId(1)] No header for parent block 13665, so will not validate continuity
DEBUG [1596603680.305] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 1 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13667
DEBUG [1596603680.317] [src/burnchains/bitcoin/indexer.rs:509] [ThreadId(1)] Search for reorg'ed Bitcoin headers from 13667 - 13683
DEBUG [1596603680.317] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603680.453] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603680.453] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=76201950009337365) to 35.221.35.47:18444
DEBUG [1596603680.734] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603680.734] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603680.734] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603680.734] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603680.734] [src/burnchains/bitcoin/spv.rs:660] [ThreadId(1)] Get headers 13667-13682 to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603680.734] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 112fac265dfa98b0ac8fea0e6625cc8fbf6f640f37d1058462f398c14b72afc6 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603680.869] [src/burnchains/bitcoin/network.rs:297] [ThreadId(1)] Handle ping 3813971999287999664
DEBUG [1596603680.869] [src/burnchains/bitcoin/network.rs:300] [ThreadId(1)] Send pong 3813971999287999664
DEBUG [1596603680.871] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 15 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13667-13682
DEBUG [1596603680.871] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13682, so will not validate continuity
DEBUG [1596603680.871] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 15 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13668
DEBUG [1596603680.880] [src/burnchains/bitcoin/spv.rs:271] [ThreadId(1)] Validate PoW between blocks 14112-16128
DEBUG [1596603680.880] [src/burnchains/bitcoin/spv.rs:451] [ThreadId(1)] Handled 15 Headers: 380b29a8633ba0102186031df972ce7c925004e359b7be9684dba3eaf880f6ce-708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603680.880] [src/burnchains/bitcoin/spv.rs:701] [ThreadId(1)] Request headers for blocks 13682 - 15682 in range 13667 - 13682
DEBUG [1596603680.880] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba for 2000 headers to 35.221.35.47:18444
DEBUG [1596603681.009] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(1)] Message handler indicates to stop
DEBUG [1596603681.009] [src/burnchains/bitcoin/indexer.rs:572] [ThreadId(1)] Found common Bitcoin block ancestor at height 13682: BlockHeader { version: 536870912, prev_blockhash: d75f3e9a7f20ff3a3123ebd7d56ed911212c1be0a959a9b2fbab9f9849bec103, merkle_root: 8012ebd1f17b32b5d2da3ec5d6c6ababd3675950a4d9f5fa765890cc7c9bcc14, time: 1596603665, bits: 545259519, nonce: 6 }
DEBUG [1596603681.009] [src/burnchains/bitcoin/indexer.rs:596] [ThreadId(1)] Bitcoin headers history is consistent up to 13682
DEBUG [1596603681.010] [src/burnchains/burnchain.rs:687] [ThreadId(1)] Sync headers from 13682
DEBUG [1596603681.010] [src/burnchains/bitcoin/indexer.rs:458] [ThreadId(1)] Sync all headers starting at block 13682
DEBUG [1596603681.020] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat
DEBUG [1596603681.020] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603681.154] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603681.154] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=76201950009337365) to 35.221.35.47:18444
DEBUG [1596603681.297] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603681.297] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603681.297] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603681.297] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603681.298] [src/burnchains/bitcoin/spv.rs:656] [ThreadId(1)] Have all headers up to 13682
DEBUG [1596603681.298] [src/burnchains/bitcoin/indexer.rs:394] [ThreadId(1)] begin_session() terminates conversation
DEBUG [1596603681.298] [src/burnchains/burnchain.rs:698] [ThreadId(1)] Sync'ed headers from 13682 to 13682. DB at 13682
DEBUG [1596603681.298] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:202] [ThreadId(1)] Done receiving blocks
DEBUG [1596603683.021] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603683.022] [src/net/p2p.rs:1660] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): begin obtaining public IP address
DEBUG [1596603683.023] [src/net/p2p.rs:1707] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Did not find any outbound neighbors to ask for a NAT punch reply
DEBUG [1596603683.023] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603683.023] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603683.023] [src/net/inv.rs:1070] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle inv sync until 1596603722s
DEBUG [1596603683.023] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603683.023] [src/net/download.rs:1399] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle block downloads until 1596603732
DEBUG [1596603683.023] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603683.024] [src/net/neighbors.rs:2022] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk state is HandshakeFinish
DEBUG [1596603683.024] [src/net/chat.rs:1200] [ThreadId(7)] convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): sent 0 bytes
DEBUG [1596603683.024] [src/net/neighbors.rs:2117] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk has taken 8 steps (total of 0 walks)
DEBUG [1596603683.024] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603683.064] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603683.066] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 5000) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603686.300] [src/chainstate/burn/db/sortdb.rs:1072] [ThreadId(1)] Connect/Open sortdb '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/data.db' as 'readwrite', with index as '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf'
DEBUG [1596603686.300] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(1)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf;
DEBUG [1596603686.374] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603686.376] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 1 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13666-13667
DEBUG [1596603686.377] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13667, so will not validate continuity
DEBUG [1596603686.377] [src/burnchains/bitcoin/spv.rs:559] [ThreadId(1)] No header for parent block 13665, so will not validate continuity
DEBUG [1596603686.377] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 1 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13667
DEBUG [1596603686.391] [src/burnchains/bitcoin/indexer.rs:509] [ThreadId(1)] Search for reorg'ed Bitcoin headers from 13667 - 13683
DEBUG [1596603686.391] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603686.527] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603686.527] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=14686023208096904919) to 35.221.35.47:18444
DEBUG [1596603686.677] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603686.677] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603686.677] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603686.677] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603686.677] [src/burnchains/bitcoin/spv.rs:660] [ThreadId(1)] Get headers 13667-13682 to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603686.677] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 112fac265dfa98b0ac8fea0e6625cc8fbf6f640f37d1058462f398c14b72afc6 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603686.829] [src/burnchains/bitcoin/network.rs:297] [ThreadId(1)] Handle ping 5684685402384773026
DEBUG [1596603686.829] [src/burnchains/bitcoin/network.rs:300] [ThreadId(1)] Send pong 5684685402384773026
DEBUG [1596603686.971] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 15 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13667-13682
DEBUG [1596603686.972] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13682, so will not validate continuity
DEBUG [1596603686.972] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 15 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13668
DEBUG [1596603686.978] [src/burnchains/bitcoin/spv.rs:271] [ThreadId(1)] Validate PoW between blocks 14112-16128
DEBUG [1596603686.978] [src/burnchains/bitcoin/spv.rs:451] [ThreadId(1)] Handled 15 Headers: 380b29a8633ba0102186031df972ce7c925004e359b7be9684dba3eaf880f6ce-708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603686.979] [src/burnchains/bitcoin/spv.rs:701] [ThreadId(1)] Request headers for blocks 13682 - 15682 in range 13667 - 13682
DEBUG [1596603686.979] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba for 2000 headers to 35.221.35.47:18444
DEBUG [1596603687.119] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(1)] Message handler indicates to stop
DEBUG [1596603687.120] [src/burnchains/bitcoin/indexer.rs:572] [ThreadId(1)] Found common Bitcoin block ancestor at height 13682: BlockHeader { version: 536870912, prev_blockhash: d75f3e9a7f20ff3a3123ebd7d56ed911212c1be0a959a9b2fbab9f9849bec103, merkle_root: 8012ebd1f17b32b5d2da3ec5d6c6ababd3675950a4d9f5fa765890cc7c9bcc14, time: 1596603665, bits: 545259519, nonce: 6 }
DEBUG [1596603687.120] [src/burnchains/bitcoin/indexer.rs:596] [ThreadId(1)] Bitcoin headers history is consistent up to 13682
DEBUG [1596603687.120] [src/burnchains/burnchain.rs:687] [ThreadId(1)] Sync headers from 13682
DEBUG [1596603687.120] [src/burnchains/bitcoin/indexer.rs:458] [ThreadId(1)] Sync all headers starting at block 13682
DEBUG [1596603687.128] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat
DEBUG [1596603687.128] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603687.265] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603687.265] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=14686023208096904919) to 35.221.35.47:18444
DEBUG [1596603687.411] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603687.411] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603687.411] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603687.411] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603687.411] [src/burnchains/bitcoin/spv.rs:656] [ThreadId(1)] Have all headers up to 13682
DEBUG [1596603687.411] [src/burnchains/bitcoin/indexer.rs:394] [ThreadId(1)] begin_session() terminates conversation
DEBUG [1596603687.411] [src/burnchains/burnchain.rs:698] [ThreadId(1)] Sync'ed headers from 13682 to 13682. DB at 13682
DEBUG [1596603687.412] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:202] [ThreadId(1)] Done receiving blocks
DEBUG [1596603688.098] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603688.099] [src/net/p2p.rs:1660] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): begin obtaining public IP address
DEBUG [1596603688.101] [src/net/p2p.rs:1707] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Did not find any outbound neighbors to ask for a NAT punch reply
DEBUG [1596603688.101] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603688.101] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603688.101] [src/net/inv.rs:1070] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle inv sync until 1596603722s
DEBUG [1596603688.101] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603688.101] [src/net/download.rs:1399] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle block downloads until 1596603732
DEBUG [1596603688.101] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603688.101] [src/net/neighbors.rs:2022] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk state is HandshakeFinish
DEBUG [1596603688.101] [src/net/chat.rs:1200] [ThreadId(7)] convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): sent 0 bytes
DEBUG [1596603688.101] [src/net/neighbors.rs:2117] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk has taken 9 steps (total of 0 walks)
DEBUG [1596603688.101] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603688.143] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603688.145] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 5000) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603692.414] [src/chainstate/burn/db/sortdb.rs:1072] [ThreadId(1)] Connect/Open sortdb '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/data.db' as 'readwrite', with index as '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf'
DEBUG [1596603692.414] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(1)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf;
DEBUG [1596603692.490] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603692.492] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 1 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13666-13667
DEBUG [1596603692.493] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13667, so will not validate continuity
DEBUG [1596603692.493] [src/burnchains/bitcoin/spv.rs:559] [ThreadId(1)] No header for parent block 13665, so will not validate continuity
DEBUG [1596603692.493] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 1 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13667
DEBUG [1596603692.509] [src/burnchains/bitcoin/indexer.rs:509] [ThreadId(1)] Search for reorg'ed Bitcoin headers from 13667 - 13683
DEBUG [1596603692.509] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603692.646] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603692.646] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=4261038386641014409) to 35.221.35.47:18444
DEBUG [1596603692.785] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603692.785] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603692.785] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603692.785] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603692.785] [src/burnchains/bitcoin/spv.rs:660] [ThreadId(1)] Get headers 13667-13682 to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603692.785] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 112fac265dfa98b0ac8fea0e6625cc8fbf6f640f37d1058462f398c14b72afc6 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603692.920] [src/burnchains/bitcoin/network.rs:297] [ThreadId(1)] Handle ping 14308395449564016079
DEBUG [1596603692.920] [src/burnchains/bitcoin/network.rs:300] [ThreadId(1)] Send pong 14308395449564016079
DEBUG [1596603692.921] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 15 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13667-13682
DEBUG [1596603692.922] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13682, so will not validate continuity
DEBUG [1596603692.922] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 15 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13668
DEBUG [1596603692.930] [src/burnchains/bitcoin/spv.rs:271] [ThreadId(1)] Validate PoW between blocks 14112-16128
DEBUG [1596603692.930] [src/burnchains/bitcoin/spv.rs:451] [ThreadId(1)] Handled 15 Headers: 380b29a8633ba0102186031df972ce7c925004e359b7be9684dba3eaf880f6ce-708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603692.930] [src/burnchains/bitcoin/spv.rs:701] [ThreadId(1)] Request headers for blocks 13682 - 15682 in range 13667 - 13682
DEBUG [1596603692.930] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba for 2000 headers to 35.221.35.47:18444
DEBUG [1596603693.181] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603693.182] [src/net/p2p.rs:1660] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): begin obtaining public IP address
DEBUG [1596603693.183] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(1)] Message handler indicates to stop
DEBUG [1596603693.184] [src/burnchains/bitcoin/indexer.rs:572] [ThreadId(1)] Found common Bitcoin block ancestor at height 13682: BlockHeader { version: 536870912, prev_blockhash: d75f3e9a7f20ff3a3123ebd7d56ed911212c1be0a959a9b2fbab9f9849bec103, merkle_root: 8012ebd1f17b32b5d2da3ec5d6c6ababd3675950a4d9f5fa765890cc7c9bcc14, time: 1596603665, bits: 545259519, nonce: 6 }
DEBUG [1596603693.184] [src/burnchains/bitcoin/indexer.rs:596] [ThreadId(1)] Bitcoin headers history is consistent up to 13682
DEBUG [1596603693.184] [src/burnchains/burnchain.rs:687] [ThreadId(1)] Sync headers from 13682
DEBUG [1596603693.184] [src/burnchains/bitcoin/indexer.rs:458] [ThreadId(1)] Sync all headers starting at block 13682
DEBUG [1596603693.186] [src/net/p2p.rs:1707] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Did not find any outbound neighbors to ask for a NAT punch reply
DEBUG [1596603693.186] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603693.186] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603693.186] [src/net/inv.rs:1070] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle inv sync until 1596603722s
DEBUG [1596603693.186] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603693.186] [src/net/download.rs:1399] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle block downloads until 1596603732
DEBUG [1596603693.186] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603693.186] [src/net/neighbors.rs:2022] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk state is HandshakeFinish
DEBUG [1596603693.186] [src/net/chat.rs:1200] [ThreadId(7)] convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): sent 0 bytes
DEBUG [1596603693.186] [src/net/neighbors.rs:2117] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk has taken 10 steps (total of 0 walks)
DEBUG [1596603693.186] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603693.189] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat
DEBUG [1596603693.189] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603693.239] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603693.241] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 5000) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603693.320] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603693.320] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=4261038386641014409) to 35.221.35.47:18444
DEBUG [1596603693.460] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13682
DEBUG [1596603693.460] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603693.460] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603693.460] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13682 blocks
DEBUG [1596603693.460] [src/burnchains/bitcoin/spv.rs:656] [ThreadId(1)] Have all headers up to 13682
DEBUG [1596603693.460] [src/burnchains/bitcoin/indexer.rs:394] [ThreadId(1)] begin_session() terminates conversation
DEBUG [1596603693.460] [src/burnchains/burnchain.rs:698] [ThreadId(1)] Sync'ed headers from 13682 to 13682. DB at 13682
DEBUG [1596603693.461] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:202] [ThreadId(1)] Done receiving blocks
DEBUG [1596603698.272] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603698.272] [src/net/p2p.rs:1660] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): begin obtaining public IP address
DEBUG [1596603698.272] [src/net/p2p.rs:1707] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Did not find any outbound neighbors to ask for a NAT punch reply
DEBUG [1596603698.275] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603698.275] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603758
DEBUG [1596603698.275] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603698.275] [src/net/inv.rs:1070] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle inv sync until 1596603722s
DEBUG [1596603698.275] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603698.275] [src/net/download.rs:1399] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Throttle block downloads until 1596603732
DEBUG [1596603698.276] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603698.276] [src/net/neighbors.rs:2022] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): walk state is HandshakeFinish
DEBUG [1596603698.276] [src/net/chat.rs:1200] [ThreadId(7)] convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): sent 0 bytes
DEBUG [1596603698.276] [src/net/neighbors.rs:542] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Failed to get Handshake reply from facade01+80000000://V4(35.245.47.179:20444): RecvTimeout
DEBUG [1596603698.276] [src/net/connection.rs:1120] [ThreadId(7)] Request timed out: seq=955784534 ttl=1596603694 now=1596603698
DEBUG [1596603698.276] [src/net/p2p.rs:1480] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Disconnect unresponsive unauthenticated peer convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): 1596603664 + 30 < 1596603698
DEBUG [1596603698.276] [src/net/poll.rs:224] [ThreadId(7)] Socket deregistered: 706, TcpStream { addr: V4(192.168.0.13:38410), peer: V4(35.245.47.179:20444), fd: 40 } (Events total: 2, max: 800)
DEBUG [1596603698.413] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603698.441] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603698.443] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 5000) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603698.461] [src/chainstate/burn/db/sortdb.rs:1072] [ThreadId(1)] Connect/Open sortdb '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/data.db' as 'readwrite', with index as '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf'
DEBUG [1596603698.461] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(1)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf;
DEBUG [1596603698.525] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603698.527] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 1 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13666-13667
DEBUG [1596603698.528] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13667, so will not validate continuity
DEBUG [1596603698.528] [src/burnchains/bitcoin/spv.rs:559] [ThreadId(1)] No header for parent block 13665, so will not validate continuity
DEBUG [1596603698.528] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 1 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13667
DEBUG [1596603698.542] [src/burnchains/bitcoin/indexer.rs:509] [ThreadId(1)] Search for reorg'ed Bitcoin headers from 13667 - 13683
DEBUG [1596603698.542] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603698.681] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603698.681] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=2954566048620672009) to 35.221.35.47:18444
DEBUG [1596603698.827] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13683
DEBUG [1596603698.827] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603698.827] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603698.827] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13683 blocks
DEBUG [1596603698.827] [src/burnchains/bitcoin/spv.rs:660] [ThreadId(1)] Get headers 13667-13683 to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603698.828] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 112fac265dfa98b0ac8fea0e6625cc8fbf6f640f37d1058462f398c14b72afc6 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603698.966] [src/burnchains/bitcoin/network.rs:297] [ThreadId(1)] Handle ping 17700291097065503991
DEBUG [1596603698.966] [src/burnchains/bitcoin/network.rs:300] [ThreadId(1)] Send pong 17700291097065503991
DEBUG [1596603698.967] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 16 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13667-13683
DEBUG [1596603698.967] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13683, so will not validate continuity
DEBUG [1596603698.967] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 16 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13668
DEBUG [1596603698.974] [src/burnchains/bitcoin/spv.rs:271] [ThreadId(1)] Validate PoW between blocks 14112-16128
DEBUG [1596603698.974] [src/burnchains/bitcoin/spv.rs:451] [ThreadId(1)] Handled 16 Headers: 380b29a8633ba0102186031df972ce7c925004e359b7be9684dba3eaf880f6ce-7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603698.974] [src/burnchains/bitcoin/spv.rs:701] [ThreadId(1)] Request headers for blocks 13683 - 15683 in range 13667 - 13683
DEBUG [1596603698.974] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603699.237] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(1)] Message handler indicates to stop
DEBUG [1596603699.238] [src/burnchains/bitcoin/indexer.rs:572] [ThreadId(1)] Found common Bitcoin block ancestor at height 13682: BlockHeader { version: 536870912, prev_blockhash: d75f3e9a7f20ff3a3123ebd7d56ed911212c1be0a959a9b2fbab9f9849bec103, merkle_root: 8012ebd1f17b32b5d2da3ec5d6c6ababd3675950a4d9f5fa765890cc7c9bcc14, time: 1596603665, bits: 545259519, nonce: 6 }
DEBUG [1596603699.238] [src/burnchains/bitcoin/indexer.rs:596] [ThreadId(1)] Bitcoin headers history is consistent up to 13682
DEBUG [1596603699.238] [src/burnchains/burnchain.rs:687] [ThreadId(1)] Sync headers from 13682
DEBUG [1596603699.238] [src/burnchains/bitcoin/indexer.rs:458] [ThreadId(1)] Sync all headers starting at block 13682
DEBUG [1596603699.244] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat
DEBUG [1596603699.244] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603699.382] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603699.382] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=2954566048620672009) to 35.221.35.47:18444
DEBUG [1596603699.529] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13683
DEBUG [1596603699.529] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603699.530] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603699.530] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13683 blocks
DEBUG [1596603699.530] [src/burnchains/bitcoin/spv.rs:660] [ThreadId(1)] Get headers 13682-13683 to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat
DEBUG [1596603699.530] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba for 2000 headers to 35.221.35.47:18444
DEBUG [1596603699.670] [src/burnchains/bitcoin/network.rs:297] [ThreadId(1)] Handle ping 16383368598940240289
DEBUG [1596603699.670] [src/burnchains/bitcoin/network.rs:300] [ThreadId(1)] Send pong 16383368598940240289
DEBUG [1596603699.802] [src/burnchains/bitcoin/spv.rs:485] [ThreadId(1)] Insert 1 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat after block 13682
DEBUG [1596603699.802] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 1 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat at 13683
DEBUG [1596603699.819] [src/burnchains/bitcoin/spv.rs:271] [ThreadId(1)] Validate PoW between blocks 12096-14112
DEBUG [1596603699.863] [src/burnchains/bitcoin/spv.rs:451] [ThreadId(1)] Handled 1 Headers: 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20-7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603699.865] [src/burnchains/bitcoin/spv.rs:701] [ThreadId(1)] Request headers for blocks 13683 - 15683 in range 13682 - 13683
DEBUG [1596603699.866] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603700.005] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(1)] Message handler indicates to stop
DEBUG [1596603700.005] [src/burnchains/burnchain.rs:698] [ThreadId(1)] Sync'ed headers from 13682 to 13683. DB at 13682
INFO [1596603700.005] [src/burnchains/burnchain.rs:704] [ThreadId(1)] Node will fetch burnchain blocks 13682-13683...
DEBUG [1596603700.005] [src/burnchains/burnchain.rs:777] [ThreadId(1)] Downloading burnchain block 13683 out of 13683...
DEBUG [1596603700.011] [src/burnchains/burnchain.rs:720] [ThreadId(10041)] Try recv next header
DEBUG [1596603700.011] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(10041)] (Re)establish peer connection
DEBUG [1596603700.144] [src/burnchains/bitcoin/network.rs:164] [ThreadId(10041)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603700.144] [src/burnchains/bitcoin/network.rs:251] [ThreadId(10041)] Send version (nonce=10132777907043514310) to 35.221.35.47:18444
DEBUG [1596603700.289] [src/burnchains/bitcoin/network.rs:259] [ThreadId(10041)] Handle version -- remote peer blockchain height is 13683
DEBUG [1596603700.289] [src/burnchains/bitcoin/network.rs:274] [ThreadId(10041)] Send verack
DEBUG [1596603700.289] [src/burnchains/bitcoin/network.rs:283] [ThreadId(10041)] Handle verack
DEBUG [1596603700.290] [src/burnchains/bitcoin/network.rs:172] [ThreadId(10041)] Established connection to 35.221.35.47:18444, who has 13683 blocks
DEBUG [1596603700.290] [src/burnchains/bitcoin/network.rs:354] [ThreadId(10041)] Send GetData 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20-7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20 to 35.221.35.47:18444
DEBUG [1596603700.426] [src/burnchains/bitcoin/network.rs:297] [ThreadId(10041)] Handle ping 9578598292712316430
DEBUG [1596603700.426] [src/burnchains/bitcoin/network.rs:300] [ThreadId(10041)] Send pong 9578598292712316430
DEBUG [1596603700.427] [src/burnchains/bitcoin/blocks.rs:219] [ThreadId(10041)] Got block 13683: 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603700.427] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(10041)] Message handler indicates to stop
DEBUG [1596603700.428] [src/burnchains/burnchain.rs:726] [ThreadId(10041)] Downloaded block 13683 in 417ms
DEBUG [1596603700.428] [src/burnchains/burnchain.rs:738] [ThreadId(10042)] Try recv next block
DEBUG [1596603700.439] [src/burnchains/burnchain.rs:744] [ThreadId(10042)] Parsed block 13683 in 11ms
DEBUG [1596603700.439] [src/burnchains/burnchain.rs:757] [ThreadId(10043)] Try recv next parsed block
DEBUG [1596603700.439] [src/burnchains/burnchain.rs:590] [ThreadId(10043)] Process block 13683 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603700.439] [src/burnchains/db.rs:232] [ThreadId(10043)] Extract Blockstack transactions from block 13683 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603700.452] [src/chainstate/burn/db/processing.rs:148] [ThreadId(10043)] BEGIN(13683) block (7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20,708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba) with sortition_id: 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603700.452] [src/chainstate/burn/db/processing.rs:150] [ThreadId(10043)] Append 4 operation(s) from block 13683 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603700.452] [src/chainstate/burn/db/processing.rs:79] [ThreadId(10043)] Check Blockstack transactions from sortition_id: 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603700.579] [src/burnchains/burnchain.rs:510] [ThreadId(10043)] Check Blockstack transactions: reject duplicate VRF keys
DEBUG [1596603700.580] [src/burnchains/burnchain.rs:539] [ThreadId(10043)] Check Blockstack transactions: filter commits that consume the same VRF key
DEBUG [1596603700.619] [src/chainstate/burn/sortition.rs:116] [ThreadId(10043)] Sampled 3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628: sortition index = 0x49d8560fd96fc7d1de5be1c76c3131e072e07b77c9cf6ad5319652ee988db910
DEBUG [1596603700.622] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13682: 47b66f9160634dd9e45de43dcf7e16f4f7dcac66
DEBUG [1596603700.624] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13681: e27d272f07a1b86432dc730286b09bf9bf85b509
DEBUG [1596603700.624] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13679: 699c135f13c6c94b95c9e8190ecd3ac4f47a8673
DEBUG [1596603700.628] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13675: 33ebcf768b4cc66237e2816ccf724d951903e725
DEBUG [1596603700.628] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13667: f826aed4bbc300bc04d3577c80b0bf6a6eb5ff69
DEBUG [1596603700.632] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13651: db4208859fd5a115f3b7e92eeb53188d60cd1517
DEBUG [1596603700.633] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13619: 16e3610aae57b12341abad70f277b3be41106d38
DEBUG [1596603700.633] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13555: de10967cd4a75a0ca2b93476e6afca02b65ea92b
DEBUG [1596603700.634] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13427: a2086654e47c96f970d6620e892c6c559eac6407
DEBUG [1596603700.634] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 13171: 30b69504b25b9e2c908ac09cf7d9fea6bfa56457
DEBUG [1596603700.635] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 12659: 7f2004e9fda91ffa5059f864c7e6f10b91cf1571
DEBUG [1596603700.637] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 11635: 59af66289d8587ee25552ea4f9c91d4d6b0cf89f
DEBUG [1596603700.637] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 9587: 27324e13ae375b79503430be203c2961ade86450
DEBUG [1596603700.638] [src/chainstate/burn/mod.rs:284] [ThreadId(10043)] Consensus at 5491: a0eacc71ad423fd5d26dc5b1548052a05c260e3f
DEBUG [1596603700.638] [src/chainstate/burn/sortition.rs:288] [ThreadId(10043)] SORTITION(13683): WINNER IS 3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628 (from e796a5fb4d945a6f9b9307f6f1aae4023592c0e36339932832de676bb2394db6)
DEBUG [1596603700.664] [src/chainstate/burn/db/sortdb.rs:1955] [ThreadId(10043)] New Stacks anchored block arrived since 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba: block 577 (61701a0e21e5c84cfd9b33bd140ab630f962fc7411a889b85fb55372f609a465) ari=577 tip=708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603700.666] [src/chainstate/burn/db/sortdb.rs:1987] [ThreadId(10043)] Max arrival for child of 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba is 577
DEBUG [1596603700.666] [src/chainstate/stacks/index/marf.rs:748] [ThreadId(10043)] Extending off of existing node 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba in /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf
DEBUG [1596603700.667] [src/chainstate/stacks/index/marf.rs:239] [ThreadId(10043)] Extend 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba to 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603700.675] [src/chainstate/stacks/index/marf.rs:631] [ThreadId(10043)] Set __MARF_BLOCK_HEIGHT_TO_HASH::13683 = 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603700.675] [src/chainstate/stacks/index/marf.rs:632] [ThreadId(10043)] Set __MARF_BLOCK_HASH_TO_HEIGHT::7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20 = 13683
DEBUG [1596603700.675] [src/chainstate/stacks/index/marf.rs:633] [ThreadId(10043)] Set __MARF_BLOCK_HEIGHT_SELF = 13683
DEBUG [1596603700.675] [src/chainstate/stacks/index/marf.rs:648] [ThreadId(10043)] Set __MARF_BLOCK_HEIGHT_TO_HASH::13682 = 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603700.675] [src/chainstate/stacks/index/marf.rs:649] [ThreadId(10043)] Set __MARF_BLOCK_HASH_TO_HEIGHT::708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba = 13682
DEBUG [1596603700.675] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: 'd3b3d3aa9f9a2fdd3636ae2b6600f414fbbaa0d1385568c99707d59f4526eff1' = '73350000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603700.685] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is ed6d554ab8c07638ebdb974c81a5fbf6bb883056f8d9f464de2d02ad868d2e61 (update_skiplist=false)
DEBUG [1596603700.685] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '954a5ec59cc5080bd95de574fe81b347cc4e44ea99be306e1cbe122a383794a9' = '7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d200000000000000000' (...[])
DEBUG [1596603700.693] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 740c76cb67fb451c91fe94e1f0ff285b55b75af0e3bcf6039642bc55fda14305 (update_skiplist=false)
DEBUG [1596603700.703] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '1b0a62a302470299d837aff8755a9b9375270a833dd4586962a907b515ad129c' = '73350000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603700.707] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 0cb10bc48d6e2b818583812b26c7ccfbef0f39ee001e71ca21891fa663a2ae19 (update_skiplist=false)
DEBUG [1596603700.708] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '41c7fa32e7addb748e39f9af799ef6f8af45bb37003f177ddf4fd30a038266fc' = '708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba0000000000000000' (...[])
DEBUG [1596603700.720] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 3bea63e270929d314f9c8bdc7fe1f3582af006060593fb6143cc174bcff11d62 (update_skiplist=false)
DEBUG [1596603700.721] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: 'a176f6820c3cc170e368e8d3913eb83cac1e5cc7dd3905663a0e959d1f187abd' = '72350000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603700.731] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 24409ad0b0504aff097f60e1e99b799490389c56166b9d0b7640f188bcb7c44b (update_skiplist=true)
DEBUG [1596603700.731] [src/chainstate/stacks/index/marf.rs:782] [ThreadId(10043)] Opened 708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba to 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20 in /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf
DEBUG [1596603700.732] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '31c6708d8717b2b47c783e08730971fffc507e5f401f07681d938b6d007b5f76' = '18d27566bd1ac66b2332d8c54ad43f7bb22079c906d05f491f3f07a28d5c69900000000000000000' (...[])
DEBUG [1596603700.738] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is def0162567a9210c3246474e83a143d462b30fdc525757feff7bdbd15b3b0983 (update_skiplist=false)
DEBUG [1596603700.739] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '8023d1653e280f138d05e48ef0a020312d3555fa918aa36bbf09fc476fa3276f' = 'f329a259ce39701e259956818e1b15eecee59460159d9158a55a885feb6121100000000000000000' (...[])
DEBUG [1596603700.746] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 0a61fc164d4b21fcd74ce34b74222ef1aadf44b3048646bb3902c582ad76ea4b (update_skiplist=false)
DEBUG [1596603700.746] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '329c6b2c09f1aaea86c107ad8e7f164c7f7134ec8829f2f843527ca6545ff9fd' = 'f329a259ce39701e259956818e1b15eecee59460159d9158a55a885feb6121100000000000000000' (...[])
DEBUG [1596603700.754] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is b37a66d6db2426142253c25ddae8504a15f35e0ff66c1392eee8cd620d33d573 (update_skiplist=false)
DEBUG [1596603700.754] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '46f5f7e574076ea9491fec3e9c92e1e6ea8ae8ccea98ba522e38ee1dfc9145e8' = 'f329a259ce39701e259956818e1b15eecee59460159d9158a55a885feb6121100000000000000000' (...[])
DEBUG [1596603700.764] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 671760b87a1ed4c08e46ec66e4c4d890a6294928943ddac6a67c1a91695340ec (update_skiplist=false)
DEBUG [1596603700.764] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: 'd11913e600ad921f904ea86d5bb82684b6295f67a81e796c4e4fc27e2655215d' = 'c47d6af1a217eae5444437dd15febe8e0f55f54ac7874eb3b67a85832bb28ee40000000000000000' (...[])
DEBUG [1596603700.767] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is e97a237b03a7d5566af4424496000eaa9ef2adf90970f391b312d037759a10f6 (update_skiplist=false)
DEBUG [1596603700.767] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '3210ef886b0c8125385edff071d2039acd12ec15425d962abe28fad67cfd313b' = 'c47d6af1a217eae5444437dd15febe8e0f55f54ac7874eb3b67a85832bb28ee40000000000000000' (...[])
DEBUG [1596603700.767] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is d3102eb419d65efcf16bee8f32ac67cae7305676cf321e780211ddc27b6be85e (update_skiplist=false)
DEBUG [1596603700.768] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: 'f1e13d5886df4d00577537536806ad0c9d5c597502a31b7e601daf41d675cd0e' = 'c47d6af1a217eae5444437dd15febe8e0f55f54ac7874eb3b67a85832bb28ee40000000000000000' (...[])
DEBUG [1596603700.775] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 20a639ddc7718eef524aa00506bf84c2114051b9bad187c166b538783e84618f (update_skiplist=false)
DEBUG [1596603700.775] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: 'f0391eebc32f932269f4277d4826bf958db88071bd4ea662c8dd3fbda2c1eec1' = '20153e339cca8972779e7eed35e9a85434cff219eb3f9689c166f707b090cbbe0000000000000000' (...[])
DEBUG [1596603700.782] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 05da2e224b582b2ee1b15c100bc6d0c41af7709e64a6ff5f91b71d4cd2a8f7f5 (update_skiplist=false)
DEBUG [1596603700.783] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(10043)] MARF Insert in 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20: '4aa445e2891853300e4901d67c6d3b850a6d4e89f9ade93e196aa35d7e888202' = '20153e339cca8972779e7eed35e9a85434cff219eb3f9689c166f707b090cbbe0000000000000000' (...[])
DEBUG [1596603700.790] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(10043)] Next root hash is 52ff631c568c6099d6647431afdbad3b5c8cecc695de772c1c59aaf3ac50b3f6 (update_skiplist=true)
DEBUG [1596603700.790] [src/chainstate/burn/db/sortdb.rs:1718] [ThreadId(10043)] ACCEPTED(13683) leader block commit e796a5fb4d945a6f9b9307f6f1aae4023592c0e36339932832de676bb2394db6 at 13683,1
DEBUG [1596603700.797] [src/chainstate/burn/db/sortdb.rs:1718] [ThreadId(10043)] ACCEPTED(13683) leader block commit 90efe94beb0958aea4d07f6f6baaf95e545fa16aa6eceb6607df56454f982adf at 13683,2
DEBUG [1596603700.797] [src/chainstate/burn/db/sortdb.rs:1714] [ThreadId(10043)] ACCEPTED(13683) leader key register d732c36e8c7b28195bf09a6618034d56d169768e7d22d269e43859c81b85a093 at 13683,3
DEBUG [1596603700.801] [src/chainstate/burn/db/sortdb.rs:1718] [ThreadId(10043)] ACCEPTED(13683) leader block commit 9347f689ef807a370a9f5f5229d333173af09ffb002e45a8eb347247fa31ea8b at 13683,4
DEBUG [1596603700.802] [src/chainstate/burn/db/processing.rs:133] [ThreadId(10043)] OPS-HASH(13683): 38e61954c1627a633a5a6bd6d9b80cb1a6056411dbc463bc4326a907c472e3a6
DEBUG [1596603700.802] [src/chainstate/burn/db/processing.rs:134] [ThreadId(10043)] INDEX-ROOT(13683): 52ff631c568c6099d6647431afdbad3b5c8cecc695de772c1c59aaf3ac50b3f6
DEBUG [1596603700.802] [src/chainstate/burn/db/processing.rs:135] [ThreadId(10043)] SORTITION-HASH(13683): 9a8990d31fd24ed8a64be2f4c7a90d456fe1a783443c7577eb9238e6c8c86818
DEBUG [1596603700.802] [src/chainstate/burn/db/processing.rs:136] [ThreadId(10043)] CONSENSUS(13683): 62d30d4ac2eb2c883593f2e635209f60aecf52d0
DEBUG [1596603700.822] [src/chainstate/stacks/index/storage.rs:1287] [ThreadId(10043)] Flush: 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20 to self
DEBUG [1596603700.831] [src/chainstate/stacks/index/storage.rs:1333] [ThreadId(10043)] Flush: identifier of self is 13684
DEBUG [1596603700.831] [src/burnchains/burnchain.rs:768] [ThreadId(10043)] Inserted block 13683 in 392ms
DEBUG [1596603700.832] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:202] [ThreadId(1)] Done receiving blocks
DEBUG [1596603700.834] [src/chainstate/burn/db/sortdb.rs:1023] [ThreadId(1)] Open sortdb '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/data.db' as 'readwrite', with index as '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf'
DEBUG [1596603700.834] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(1)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf;
INFO [1596603700.864] [testnet/stacks-node/src/neon_node.rs:882] [ThreadId(1)] Received burnchain block #13683 including block_commit_op (winning) - n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
INFO [1596603700.865] [testnet/stacks-node/src/neon_node.rs:891] [ThreadId(1)] Received burnchain block #13683 including block_commit_op - mz6Dg9kkedkimvVxVZduUY14L8rN1QgthP
INFO [1596603700.867] [testnet/stacks-node/src/neon_node.rs:891] [ThreadId(1)] Received burnchain block #13683 including block_commit_op - mx2uds6sgnn9znABQ6iDSSmXY9K5D4SHF9
INFO [1596603700.879] [testnet/stacks-node/src/neon_node.rs:902] [ThreadId(1)] Received burnchain block #13683 including key_register_op - ST2TJRHDHMYBQ417HFB0BDX430TQA5PXRX6495G1V
DEBUG [1596603700.881] [testnet/stacks-node/src/neon_node.rs:421] [ThreadId(6)] Relayer: Process tenure
INFO [1596603700.881] [testnet/stacks-node/src/neon_node.rs:431] [ThreadId(6)] Won sortition! stacks_header=3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628, burn_header=708fe9b383890c5200361c1111d5c3865b098337b985dc50dfc5b097ca5b8bba
DEBUG [1596603700.881] [src/chainstate/stacks/db/blocks.rs:2270] [ThreadId(6)] preprocess anchored block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628
WARN [1596603700.892] [testnet/stacks-node/src/neon_node.rs:684] [ThreadId(1)] Skipped tenure because no active VRF key. Trying to register one.
DEBUG [1596603700.893] [src/chainstate/burn/db/sortdb.rs:1072] [ThreadId(1)] Connect/Open sortdb '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/data.db' as 'readwrite', with index as '/tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf'
DEBUG [1596603700.893] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(1)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/burnchain/db/bitcoin/regtest/sortition.db/marf;
DEBUG [1596603700.953] [src/chainstate/burn/db/sortdb.rs:801] [ThreadId(6)] Block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628 mines off of parent 13681,1
DEBUG [1596603700.999] [src/chainstate/stacks/db/blocks.rs:2313] [ThreadId(6)] Storing staging block
DEBUG [1596603701.000] [src/chainstate/stacks/db/blocks.rs:1150] [ThreadId(6)] Store anchored block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628, parent in 03c1be49989fabfbb2a959a9e01b2c2111d96ed5d7eb23313aff207f9a3e5fd7
DEBUG [1596603701.009] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603701.009] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 1 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13667-13668
DEBUG [1596603701.009] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13668, so will not validate continuity
DEBUG [1596603701.009] [src/burnchains/bitcoin/spv.rs:559] [ThreadId(1)] No header for parent block 13666, so will not validate continuity
DEBUG [1596603701.009] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 1 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13668
DEBUG [1596603701.019] [src/burnchains/bitcoin/indexer.rs:509] [ThreadId(1)] Search for reorg'ed Bitcoin headers from 13668 - 13684
DEBUG [1596603701.019] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603701.019] [src/chainstate/stacks/db/blocks.rs:3148] [ThreadId(6)] Process up to 1 blocks
DEBUG [1596603701.019] [src/chainstate/stacks/db/blocks.rs:2561] [ThreadId(6)] Consider block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628 whose parent is 03c1be49989fabfbb2a959a9e01b2c2111d96ed5d7eb23313aff207f9a3e5fd7/61701a0e21e5c84cfd9b33bd140ab630f962fc7411a889b85fb55372f609a465
DEBUG [1596603701.019] [src/chainstate/stacks/db/blocks.rs:2587] [ThreadId(6)] Have parent 03c1be49989fabfbb2a959a9e01b2c2111d96ed5d7eb23313aff207f9a3e5fd7/61701a0e21e5c84cfd9b33bd140ab630f962fc7411a889b85fb55372f609a465 for this block, will process
DEBUG [1596603701.019] [src/chainstate/stacks/db/blocks.rs:2957] [ThreadId(6)] Process staging block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628
DEBUG [1596603701.019] [src/chainstate/stacks/db/blocks.rs:2962] [ThreadId(6)] Found parent info 03c1be49989fabfbb2a959a9e01b2c2111d96ed5d7eb23313aff207f9a3e5fd7/61701a0e21e5c84cfd9b33bd140ab630f962fc7411a889b85fb55372f609a465
DEBUG [1596603701.020] [src/chainstate/stacks/db/blocks.rs:2112] [ThreadId(6)] No microblocks between 61701a0e21e5c84cfd9b33bd140ab630f962fc7411a889b85fb55372f609a465 and 3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628
DEBUG [1596603701.020] [src/chainstate/stacks/db/blocks.rs:2774] [ThreadId(6)] Process block "3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628" with 1 transactions
DEBUG [1596603701.021] [src/chainstate/stacks/db/accounts.rs:460] [ThreadId(6)] CACHE MISS MINER REWARDS a5c0bbe0d754c0d7020a21753ce04c139f746c8d5bdbf68e74dacdbe213f7048
DEBUG [1596603701.021] [src/chainstate/stacks/index/marf.rs:748] [ThreadId(6)] Extending off of existing node c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 in /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/clarity/marf
DEBUG [1596603701.021] [src/chainstate/stacks/index/marf.rs:239] [ThreadId(6)] Extend c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 to af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5
DEBUG [1596603701.030] [src/chainstate/stacks/index/marf.rs:631] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_TO_HASH::578 = af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5
DEBUG [1596603701.030] [src/chainstate/stacks/index/marf.rs:632] [ThreadId(6)] Set __MARF_BLOCK_HASH_TO_HEIGHT::af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5 = 578
DEBUG [1596603701.030] [src/chainstate/stacks/index/marf.rs:633] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_SELF = 578
DEBUG [1596603701.030] [src/chainstate/stacks/index/marf.rs:648] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_TO_HASH::577 = c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603701.030] [src/chainstate/stacks/index/marf.rs:649] [ThreadId(6)] Set __MARF_BLOCK_HASH_TO_HEIGHT::c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 = 577
DEBUG [1596603701.031] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: 'd3b3d3aa9f9a2fdd3636ae2b6600f414fbbaa0d1385568c99707d59f4526eff1' = '42020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.031] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 9995b88144b6046e3f1151265e7d6ed7918b6532cb151d959b3da6a7faf02569 (update_skiplist=false)
DEBUG [1596603701.031] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: '1473d818f84ff454cb4d7bd1a35521e6072b4e7252b22327a126a899f9818a50' = 'af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd50000000000000000' (...[])
DEBUG [1596603701.031] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 0db794e61517656fac976751cfe26fbf82e104140cad65e6ba22759256263cd8 (update_skiplist=false)
DEBUG [1596603701.031] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: '2216f09e7df1b25ef639a753033963a8a3701d920b7280c2942af883d467fc28' = '42020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.031] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 8fe8041964524172ad1a8d2fca59165d82eeddd10b8ef98c1f01f2a4897d90f1 (update_skiplist=false)
DEBUG [1596603701.031] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: 'e6e758b6e9a4ece197e01cfd3817f4ad53f75f84032a6e7a579d648fe7632af0' = 'c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab90000000000000000' (...[])
DEBUG [1596603701.031] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 4db2c33dba81b25981684408072d8f1ad448b4e81ce820b3935ec3eb72eb59a8 (update_skiplist=false)
DEBUG [1596603701.032] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: '45131293c4740915a8266cdcf1284c5c6640b92d76a302df24d020c3de3668ef' = '41020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.033] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 391cb18d5242f0e602d672a3e9106c65d6c2a380d5f31bcd4e06c75520b69019 (update_skiplist=true)
DEBUG [1596603701.033] [src/chainstate/stacks/index/marf.rs:782] [ThreadId(6)] Opened c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 to af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5 in /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/clarity/marf
DEBUG [1596603701.033] [src/chainstate/stacks/db/blocks.rs:2832] [ThreadId(6)]

Append block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628 off of 03c1be49989fabfbb2a959a9e01b2c2111d96ed5d7eb23313aff207f9a3e5fd7/61701a0e21e5c84cfd9b33bd140ab630f962fc7411a889b85fb55372f609a465
Stacks block height: 578, Total Burns: 326800000
Microblock parent: 0000000000000000000000000000000000000000000000000000000000000000 (seq 0) (count 0)

DEBUG [1596603701.033] [src/chainstate/stacks/db/transactions.rs:728] [ThreadId(6)] Process transaction 02dbc23fcc9ccf8bfa16fce1627f896e277cc52e1d20ade975cdc2ae4a38e96b (Coinbase)
DEBUG [1596603701.034] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: '5f9758d9e86d746a6253d13c93144fbd8183bdf548f0f6b2a1cc669d2df69951' = 'f329a259ce39701e259956818e1b15eecee59460159d9158a55a885feb6121100000000000000000' (...[])
DEBUG [1596603701.034] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is d6b131122c3f63325e389ec346cfe1fcf43cd8b125f92615c49c145083a5f926 (update_skiplist=false)
DEBUG [1596603701.035] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: 'c1f3e5c9e55e4dd19a6b188cdd68b543ff9ee4e6e87a5993c3e648d9b913fe19' = '1ebd247da12a17f91233ecaed2258bc0af1e6dfbf77ba0a0ae650149e6f725f30000000000000000' (...[])
DEBUG [1596603701.035] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 75494da8e29758d77013747ec08b6fb748b15b99537165f8ba9f24669e912f68 (update_skiplist=true)
DEBUG [1596603701.035] [src/chainstate/stacks/db/blocks.rs:2729] [ThreadId(6)] Grant miner ST3RMK4C9TXHE2CPYB58WB5MK8R4SZE8E0K6EJED5 500000000 STX. Updated to: (tuple (authorized false) (available u230500000000))
DEBUG [1596603701.036] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5: 'a8f90c0d1f5010357279825c7be10ad47843e05524d3077664833f420cfd71ff' = '850e45f41757a0d3b1c4d4393033f326890b4c3b281b84d47b8032ce51b485b00000000000000000' (...[])
DEBUG [1596603701.036] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is eeaa49fbb91ccbec36077d30b8c9889b207383cd182318bf7615e7592c2d3966 (update_skiplist=true)
DEBUG [1596603701.040] [src/chainstate/stacks/db/blocks.rs:2867] [ThreadId(6)] Reached state root eeaa49fbb91ccbec36077d30b8c9889b207383cd182318bf7615e7592c2d3966
DEBUG [1596603701.040] [src/vm/clarity.rs:377] [ThreadId(6)] Commit Clarity datastore to 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603701.040] [src/vm/database/marf.rs:264] [ThreadId(6)] commit_to(1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042)
DEBUG [1596603701.052] [src/chainstate/stacks/index/storage.rs:1287] [ThreadId(6)] Flush: af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5 to 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603701.052] [src/chainstate/stacks/index/storage.rs:1310] [ThreadId(6)] Retarget block af425f228a92ebe4d7741b129bb2c2f4326179f682da305b030250ccea9d4cd5 to 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603701.063] [src/chainstate/stacks/index/storage.rs:1333] [ThreadId(6)] Flush: identifier of 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042 is 579
DEBUG [1596603701.063] [src/chainstate/stacks/index/marf.rs:748] [ThreadId(6)] Extending off of existing node c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 in /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/index
DEBUG [1596603701.063] [src/chainstate/stacks/index/marf.rs:239] [ThreadId(6)] Extend c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 to 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603701.073] [src/chainstate/stacks/index/marf.rs:631] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_TO_HASH::578 = 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603701.073] [src/chainstate/stacks/index/marf.rs:632] [ThreadId(6)] Set __MARF_BLOCK_HASH_TO_HEIGHT::1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042 = 578
DEBUG [1596603701.073] [src/chainstate/stacks/index/marf.rs:633] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_SELF = 578
DEBUG [1596603701.073] [src/chainstate/stacks/index/marf.rs:648] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_TO_HASH::577 = c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603701.073] [src/chainstate/stacks/index/marf.rs:649] [ThreadId(6)] Set __MARF_BLOCK_HASH_TO_HEIGHT::c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 = 577
DEBUG [1596603701.074] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042: 'd3b3d3aa9f9a2fdd3636ae2b6600f414fbbaa0d1385568c99707d59f4526eff1' = '42020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.074] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is a52687675935d4d97f6a56e21cf9f2a57e343251ec36bdb4f6b77f41a1f2938f (update_skiplist=false)
DEBUG [1596603701.074] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042: '1473d818f84ff454cb4d7bd1a35521e6072b4e7252b22327a126a899f9818a50' = '1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f0420000000000000000' (...[])
DEBUG [1596603701.074] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is e4cc05138424b4d5300bb81b38fb97d4575bca81aa978c85bffabf84c2440fbf (update_skiplist=false)
DEBUG [1596603701.074] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042: '74e9a92abc950826644b6f425158e81ed0d206ad77e027e61b13637ec7a9a3f9' = '42020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.074] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is a3f09578247381354702448a7fb668039591fad6bb3ecf63b6582056d689670b (update_skiplist=false)
DEBUG [1596603701.074] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042: 'e6e758b6e9a4ece197e01cfd3817f4ad53f75f84032a6e7a579d648fe7632af0' = 'c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab90000000000000000' (...[])
DEBUG [1596603701.074] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 313e9592a16eec24dfd6d314a5356d2a94d0f6e6f892b95906fc63141185e817 (update_skiplist=false)
DEBUG [1596603701.075] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042: '45131293c4740915a8266cdcf1284c5c6640b92d76a302df24d020c3de3668ef' = '41020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.076] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 1046c14c2986cbf1b9e2c9f4e6bf9548b9e01519fb30d20e0e4fcbdcd2e42722 (update_skiplist=true)
DEBUG [1596603701.076] [src/chainstate/stacks/index/marf.rs:782] [ThreadId(6)] Opened c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 to 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042 in /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/index
DEBUG [1596603701.076] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042: '1f347ba079e5796f439dfd9cb5ec07fe27afa0bb32983f4fe710348f3dc3cdaf' = '18d27566bd1ac66b2332d8c54ad43f7bb22079c906d05f491f3f07a28d5c69900000000000000000' (...[])
DEBUG [1596603701.076] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 91bfaa2b65fd6bb1e72c8842d8da0c75d3c747af68145023676dd413c51610ec (update_skiplist=true)
DEBUG [1596603701.086] [src/chainstate/stacks/db/mod.rs:1109] [ThreadId(6)] Advanced to new tip! 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628
DEBUG [1596603701.086] [src/chainstate/stacks/db/blocks.rs:3128] [ThreadId(6)] Reached chain tip 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628 from 03c1be49989fabfbb2a959a9e01b2c2111d96ed5d7eb23313aff207f9a3e5fd7/61701a0e21e5c84cfd9b33bd140ab630f962fc7411a889b85fb55372f609a465
DEBUG [1596603701.086] [src/chainstate/stacks/db/blocks.rs:1600] [ThreadId(6)] Accept block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628 as 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603701.151] [src/chainstate/burn/db/sortdb.rs:615] [ThreadId(6)] Accepted Stacks block 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20/3a660d505dee0e5b1fe1ad24c57e9dbe079fff2318a119dbaad1c817cca21628 builds on the memoized canonical chain tip (7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20)
DEBUG [1596603701.159] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603701.159] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=241174082512852237) to 35.221.35.47:18444
DEBUG [1596603701.173] [src/chainstate/stacks/index/storage.rs:1287] [ThreadId(6)] Flush: 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042 to self
DEBUG [1596603701.182] [src/chainstate/stacks/index/storage.rs:1333] [ThreadId(6)] Flush: identifier of self is 579
DEBUG [1596603701.195] [src/chainstate/stacks/db/blocks.rs:3148] [ThreadId(6)] Process up to 1 blocks
DEBUG [1596603701.196] [src/chainstate/stacks/db/blocks.rs:2952] [ThreadId(6)] No staging blocks
DEBUG [1596603701.196] [src/chainstate/stacks/db/blocks.rs:3172] [ThreadId(6)] No more staging blocks -- processed 0 in total
DEBUG [1596603701.239] [src/net/relay.rs:746] [ThreadId(6)] Reload unconfirmed state
DEBUG [1596603701.240] [src/chainstate/stacks/db/unconfirmed.rs:204] [ThreadId(6)] Reload unconfirmed state off of 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603701.240] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(6)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/clarity/marf;
DEBUG [1596603701.241] [src/chainstate/stacks/db/unconfirmed.rs:185] [ThreadId(6)] Drop unconfirmed state off of c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603701.241] [src/chainstate/stacks/index/marf.rs:748] [ThreadId(6)] Extending off of existing node c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 in /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/clarity/marf
DEBUG [1596603701.241] [src/chainstate/stacks/index/storage.rs:919] [ThreadId(6)] Instantiate unconfirmed trie 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374
DEBUG [1596603701.251] [src/chainstate/stacks/index/marf.rs:631] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_TO_HASH::578 = 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374
DEBUG [1596603701.251] [src/chainstate/stacks/index/marf.rs:632] [ThreadId(6)] Set __MARF_BLOCK_HASH_TO_HEIGHT::8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374 = 578
DEBUG [1596603701.251] [src/chainstate/stacks/index/marf.rs:633] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_SELF = 578
DEBUG [1596603701.252] [src/chainstate/stacks/index/marf.rs:648] [ThreadId(6)] Set __MARF_BLOCK_HEIGHT_TO_HASH::577 = c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9
DEBUG [1596603701.252] [src/chainstate/stacks/index/marf.rs:649] [ThreadId(6)] Set __MARF_BLOCK_HASH_TO_HEIGHT::c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 = 577
DEBUG [1596603701.252] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374: 'd3b3d3aa9f9a2fdd3636ae2b6600f414fbbaa0d1385568c99707d59f4526eff1' = '42020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.273] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 9995b88144b6046e3f1151265e7d6ed7918b6532cb151d959b3da6a7faf02569 (update_skiplist=false)
DEBUG [1596603701.273] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374: '1473d818f84ff454cb4d7bd1a35521e6072b4e7252b22327a126a899f9818a50' = '8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a423740000000000000000' (...[])
DEBUG [1596603701.273] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 18abcf3b9cb3bd96adeea2e0404919fedfa342392c95cf9f58fb272ce7daf4ce (update_skiplist=false)
DEBUG [1596603701.273] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374: 'c27c90d9201c068e877ea7b0023e3992e5ebcd22bd8fd5ff454c754790c0c3b5' = '42020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.274] [src/chainstate/stacks/index/trie.rs:689] [ThreadId(6)] Next root hash is 7ee317a7c5c602362dd8a986aab1efcaf9b963c914a9584b95cde05c62f9e9af (update_skiplist=false)
DEBUG [1596603701.274] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374: 'e6e758b6e9a4ece197e01cfd3817f4ad53f75f84032a6e7a579d648fe7632af0' = 'c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab90000000000000000' (...[])
DEBUG [1596603701.274] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is 3852eacc92849a7ea6495d3d9f2e8f768c3f0ea0dcb0e42aec7dd568840f9eb6 (update_skiplist=false)
DEBUG [1596603701.274] [src/chainstate/stacks/index/marf.rs:470] [ThreadId(6)] MARF Insert in 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374: '45131293c4740915a8266cdcf1284c5c6640b92d76a302df24d020c3de3668ef' = '41020000000000000000000000000000000000000000000000000000000000000000000000000000' (...[])
DEBUG [1596603701.275] [src/chainstate/stacks/index/trie.rs:745] [ThreadId(6)] Next root hash is a85b1829414645bf65385db47632262f6ea0dae6c8fc02eaaac140f3adfdaa51 (update_skiplist=true)
DEBUG [1596603701.275] [src/chainstate/stacks/index/marf.rs:782] [ThreadId(6)] Opened c76d80698f2f9be61be04c004a7c60dec3f46b8efdbe7a32e57bbc8af5399ab9 to 8c1f7ec2397b58f4641ff465b4fe0eedd5c3c5811d677fc3d1b66c5268a42374 in /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/clarity/marf
DEBUG [1596603701.275] [src/vm/clarity.rs:351] [ThreadId(6)] Rollback unconfirmed Clarity datastore
DEBUG [1596603701.288] [testnet/stacks-node/src/neon_node.rs:512] [ThreadId(6)] Relayer: Register key
DEBUG [1596603701.288] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596603701.326] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13683
DEBUG [1596603701.326] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603701.326] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603701.326] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13683 blocks
DEBUG [1596603701.326] [src/burnchains/bitcoin/spv.rs:660] [ThreadId(1)] Get headers 13668-13683 to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg
DEBUG [1596603701.326] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 380b29a8633ba0102186031df972ce7c925004e359b7be9684dba3eaf880f6ce for 2000 headers to 35.221.35.47:18444
DEBUG [1596603701.468] [src/burnchains/bitcoin/network.rs:297] [ThreadId(1)] Handle ping 6676738674764345308
DEBUG [1596603701.468] [src/burnchains/bitcoin/network.rs:300] [ThreadId(1)] Send pong 6676738674764345308
DEBUG [1596603701.471] [src/burnchains/bitcoin/spv.rs:524] [ThreadId(1)] Insert 15 headers to /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg in range 13668-13683
DEBUG [1596603701.471] [src/burnchains/bitcoin/spv.rs:545] [ThreadId(1)] No header for child block 13683, so will not validate continuity
DEBUG [1596603701.471] [src/burnchains/bitcoin/spv.rs:464] [ThreadId(1)] Write 15 headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat.reorg at 13669
DEBUG [1596603701.478] [src/burnchains/bitcoin/spv.rs:271] [ThreadId(1)] Validate PoW between blocks 14112-16128
DEBUG [1596603701.478] [src/burnchains/bitcoin/spv.rs:451] [ThreadId(1)] Handled 15 Headers: 41c9364ee78a06a3b85124c104b6c34c1e71194eb106b56586fe85e418e1da88-7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603701.478] [src/burnchains/bitcoin/spv.rs:701] [ThreadId(1)] Request headers for blocks 13683 - 15683 in range 13668 - 13683
DEBUG [1596603701.478] [src/burnchains/bitcoin/network.rs:332] [ThreadId(1)] Send GetHeaders 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20 for 2000 headers to 35.221.35.47:18444
DEBUG [1596603701.785] [src/burnchains/bitcoin/indexer.rs:418] [ThreadId(1)] Message handler indicates to stop
DEBUG [1596603701.785] [src/burnchains/bitcoin/indexer.rs:572] [ThreadId(1)] Found common Bitcoin block ancestor at height 13683: BlockHeader { version: 536870912, prev_blockhash: ba8b5bca97b0c5df50dc85b93783095b86c3d511111c3600520c8983b3e98f70, merkle_root: 957c1847cd5feeee14619b1c578fcdc1fe5b1954fe75e05310d4a83ac75e283c, time: 1596603695, bits: 545259519, nonce: 2 }
DEBUG [1596603701.785] [src/burnchains/bitcoin/indexer.rs:596] [ThreadId(1)] Bitcoin headers history is consistent up to 13683
DEBUG [1596603701.785] [src/burnchains/burnchain.rs:687] [ThreadId(1)] Sync headers from 13683
DEBUG [1596603701.785] [src/burnchains/bitcoin/indexer.rs:458] [ThreadId(1)] Sync all headers starting at block 13683
DEBUG [1596603701.791] [src/burnchains/bitcoin/spv.rs:394] [ThreadId(1)] Initialized block headers at /tmp/stacks-testnet-dc05558e9eb92010/burnchain/spv-headers.dat
DEBUG [1596603701.791] [src/burnchains/bitcoin/indexer.rs:373] [ThreadId(1)] (Re)establish peer connection
DEBUG [1596603701.933] [src/burnchains/bitcoin/network.rs:164] [ThreadId(1)] Begin peer handshake to 35.221.35.47:18444
DEBUG [1596603701.933] [src/burnchains/bitcoin/network.rs:251] [ThreadId(1)] Send version (nonce=241174082512852237) to 35.221.35.47:18444
INFO [1596603702.370] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:328] [ThreadId(6)] Miner node: submitting leader_key_register op - 039734ecea68e2e2f6fc022bc4703f8ef4f4e3b2e07fb7fc86494f6a7a0afe8197
DEBUG [1596603702.372] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:792] [ThreadId(6)] BitcoinRPC builder: None:None@http://35.221.35.47:18443/
DEBUG [1596603702.373] [src/burnchains/bitcoin/network.rs:259] [ThreadId(1)] Handle version -- remote peer blockchain height is 13683
DEBUG [1596603702.373] [src/burnchains/bitcoin/network.rs:274] [ThreadId(1)] Send verack
DEBUG [1596603702.373] [src/burnchains/bitcoin/network.rs:283] [ThreadId(1)] Handle verack
DEBUG [1596603702.373] [src/burnchains/bitcoin/network.rs:172] [ThreadId(1)] Established connection to 35.221.35.47:18444, who has 13683 blocks
DEBUG [1596603702.373] [src/burnchains/bitcoin/spv.rs:656] [ThreadId(1)] Have all headers up to 13683
DEBUG [1596603702.373] [src/burnchains/bitcoin/indexer.rs:394] [ThreadId(1)] begin_session() terminates conversation
DEBUG [1596603702.373] [src/burnchains/burnchain.rs:698] [ThreadId(1)] Sync'ed headers from 13683 to 13683. DB at 13683
DEBUG [1596603702.373] [testnet/stacks-node/src/burnchains/bitcoin_regtest_controller.rs:202] [ThreadId(1)] Done receiving blocks
DEBUG [1596603702.885] [testnet/stacks-node/src/neon_node.rs:377] [ThreadId(6)] Relayer: Try process attacheable blocks
DEBUG [1596603702.885] [src/chainstate/stacks/db/blocks.rs:3148] [ThreadId(6)] Process up to 1 blocks
DEBUG [1596603702.885] [src/chainstate/stacks/db/blocks.rs:2952] [ThreadId(6)] No staging blocks
DEBUG [1596603702.885] [src/chainstate/stacks/db/blocks.rs:3172] [ThreadId(6)] No more staging blocks -- processed 0 in total
DEBUG [1596603703.473] [src/net/p2p.rs:2669] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): load chain view for burn block 13683
DEBUG [1596603703.650] [src/net/inv.rs:1039] [ThreadId(7)] Awaken inv sync to re-scan peer block inventories
DEBUG [1596603703.652] [src/net/download.rs:661] [ThreadId(7)] Awaken downloader to restart scanning
DEBUG [1596603703.653] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603703.653] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603758
DEBUG [1596603703.653] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603703.653] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603758
DEBUG [1596603703.653] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603703.653] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvBegin
DEBUG [1596603703.653] [src/net/inv.rs:981] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Will send 0 getblocksinv requests (out of 0 active events)
DEBUG [1596603703.653] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvFinish
DEBUG [1596603703.653] [src/net/inv.rs:772] [ThreadId(7)] Still waiting for 0 blocksinv replies
DEBUG [1596603703.653] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is Done
DEBUG [1596603703.653] [src/net/inv.rs:1175] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Advanced inv-sync rescan height to 4096 from 0
DEBUG [1596603703.653] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603703.653] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is DNSLookupBegin
DEBUG [1596603703.653] [src/net/download.rs:921] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Look for blocks at sortition 0, microblocks at sortition 0
DEBUG [1596603703.656] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 0
DEBUG [1596603703.656] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (0-4096)...
DEBUG [1596603703.696] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603703.698] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4096 (3f93b440c1544631684e121b7f9fbe35a7d9c91a)
DEBUG [1596603703.704] [src/chainstate/burn/db/sortdb.rs:1208] [ThreadId(7)] CACHE MISS 7d5192af7af3c78263748aff2b529e3ec31dcd4387b12c3089a5616d0189b6c1
DEBUG [1596603703.705] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603703.707] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13681 items
DEBUG [1596603703.707] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 4096 sortitions (0-4096)
DEBUG [1596603703.738] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 0
DEBUG [1596603703.739] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (0-4096)...
DEBUG [1596603703.763] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603703.765] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4096 (3f93b440c1544631684e121b7f9fbe35a7d9c91a)
DEBUG [1596603703.771] [src/chainstate/burn/db/sortdb.rs:1208] [ThreadId(7)] CACHE MISS 7d5192af7af3c78263748aff2b529e3ec31dcd4387b12c3089a5616d0189b6c1
DEBUG [1596603703.772] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603703.774] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13681 items
DEBUG [1596603703.775] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (0-4096)
DEBUG [1596603703.805] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (4096,1) (was (0,0))
DEBUG [1596603703.807] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 4096
DEBUG [1596603703.808] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (4096-8192)...
DEBUG [1596603703.834] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603703.836] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 8192 (fd6142aa94503ef8d22fe295fdb50972ec5388e6)
DEBUG [1596603703.841] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603703.843] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13681 items
DEBUG [1596603703.845] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 4096 sortitions (4096-8192)
DEBUG [1596603703.881] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 1
DEBUG [1596603703.883] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (1-4097)...
DEBUG [1596603703.908] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603703.909] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4097 (ec01c65fb0277eec3144a3b57998a24901832026)
DEBUG [1596603703.915] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603703.916] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13681 items
DEBUG [1596603703.918] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (1-4097)
DEBUG [1596603703.950] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (8192,1) (was (0,0))
DEBUG [1596603703.951] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 8192
DEBUG [1596603703.953] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (8192-12288)...
DEBUG [1596603703.978] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603703.980] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 12288 (923e0fc7fd304bba3e60c7e01bdccccc41ffdfdc)
DEBUG [1596603703.986] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603703.988] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13681 items
DEBUG [1596603703.990] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 4096 sortitions (8192-12288)
DEBUG [1596603704.023] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 1
DEBUG [1596603704.024] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (1-4097)...
DEBUG [1596603704.053] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.055] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4097 (ec01c65fb0277eec3144a3b57998a24901832026)
DEBUG [1596603704.061] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.062] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13681 items
DEBUG [1596603704.064] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (1-4097)
DEBUG [1596603704.095] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (12288,1) (was (0,0))
DEBUG [1596603704.097] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 12288
DEBUG [1596603704.099] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (12288-16384)...
DEBUG [1596603704.124] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.125] [src/net/download.rs:542] [ThreadId(7)] Load 1395 headers off of 13683 (62d30d4ac2eb2c883593f2e635209f60aecf52d0)
DEBUG [1596603704.131] [src/chainstate/burn/db/sortdb.rs:1208] [ThreadId(7)] CACHE MISS 7d0d68c7288d18b7757baec34e7d9f5203942c2d48b08b85e9325e8d48ef0d20
DEBUG [1596603704.133] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.134] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.135] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 1395 sortitions (12288-16384)
DEBUG [1596603704.149] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 1
DEBUG [1596603704.151] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (1-4097)...
DEBUG [1596603704.178] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.179] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4097 (ec01c65fb0277eec3144a3b57998a24901832026)
DEBUG [1596603704.185] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.186] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.188] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (1-4097)
DEBUG [1596603704.219] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (13682,1) (was (0,0))
DEBUG [1596603704.220] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 13682
DEBUG [1596603704.221] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (13682-17778)...
DEBUG [1596603704.251] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.253] [src/net/download.rs:542] [ThreadId(7)] Load 1 headers off of 13683 (62d30d4ac2eb2c883593f2e635209f60aecf52d0)
DEBUG [1596603704.258] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.259] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.260] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 1 sortitions (13682-17778)
DEBUG [1596603704.261] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 1
DEBUG [1596603704.261] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (1-4097)...
DEBUG [1596603704.292] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.294] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4097 (ec01c65fb0277eec3144a3b57998a24901832026)
DEBUG [1596603704.300] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.301] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.303] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (1-4097)
DEBUG [1596603704.333] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (13682,1) (was (0,0))
DEBUG [1596603704.335] [src/net/download.rs:1058] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Will try for 0 blocks and 0 microblocks (next sortition heights are 17778,4097, chain tip is 13683)
DEBUG [1596603704.336] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is DNSLookupFinish
DEBUG [1596603704.336] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetBlocksBegin
DEBUG [1596603704.336] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetBlocksFinish
DEBUG [1596603704.336] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetMicroblocksBegin
DEBUG [1596603704.341] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetMicroblocksFinish
DEBUG [1596603704.341] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is Done
DEBUG [1596603704.341] [src/net/download.rs:1307] [ThreadId(7)] Blocks to try: 0; Microblocks to try: 0
DEBUG [1596603704.341] [src/net/download.rs:1312] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Advance downloader to start at sortition heights 17778,4097
DEBUG [1596603704.341] [src/net/download.rs:1317] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Downloader for blocks has reached the chain tip
DEBUG [1596603704.341] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603704.341] [src/net/neighbors.rs:1447] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): failed to begin inbound neighbor walk: no one's connected to us
DEBUG [1596603704.341] [src/net/neighbors.rs:1991] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Failed to begin neighbor walk from pingback: NoSuchNeighbor
DEBUG [1596603704.341] [src/net/p2p.rs:723] [ThreadId(7)] Inbound recipient distribution: {}
DEBUG [1596603704.341] [src/net/p2p.rs:724] [ThreadId(7)] Outbound recipient distribution: {}
DEBUG [1596603704.341] [src/net/p2p.rs:729] [ThreadId(7)] Inbound recipients: []
DEBUG [1596603704.341] [src/net/p2p.rs:730] [ThreadId(7)] Outbound recipients: []
DEBUG [1596603704.341] [src/net/p2p.rs:587] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Will broadcast 'Blocks' to up to 0 neighbors
DEBUG [1596603704.341] [src/net/p2p.rs:604] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Done broadcasting 'Blocks
DEBUG [1596603704.341] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603704.341] [testnet/stacks-node/src/neon_node.rs:270] [ThreadId(7)] P2P: backpressure: false, more downloads: true
DEBUG [1596603704.390] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603704.392] [src/chainstate/stacks/index/storage.rs:661] [ThreadId(7)] Opened TrieFileStorage /tmp/stacks-testnet-dc05558e9eb92010/chainstate/chain-00000080-testnet/vm/clarity/marf;
DEBUG [1596603704.394] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 100) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603704.521] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603704.522] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603758
DEBUG [1596603704.523] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603704.523] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603758
DEBUG [1596603704.523] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603704.523] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvBegin
DEBUG [1596603704.523] [src/net/inv.rs:981] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Will send 0 getblocksinv requests (out of 0 active events)
DEBUG [1596603704.523] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvFinish
DEBUG [1596603704.523] [src/net/inv.rs:772] [ThreadId(7)] Still waiting for 0 blocksinv replies
DEBUG [1596603704.523] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is Done
DEBUG [1596603704.523] [src/net/inv.rs:1175] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Advanced inv-sync rescan height to 8192 from 4096
DEBUG [1596603704.523] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603704.523] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is DNSLookupBegin
DEBUG [1596603704.523] [src/net/download.rs:921] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Look for blocks at sortition 0, microblocks at sortition 4097
DEBUG [1596603704.523] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 0
DEBUG [1596603704.523] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (0-4096)...
DEBUG [1596603704.563] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.564] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4096 (3f93b440c1544631684e121b7f9fbe35a7d9c91a)
DEBUG [1596603704.571] [src/chainstate/burn/db/sortdb.rs:1208] [ThreadId(7)] CACHE MISS 7d5192af7af3c78263748aff2b529e3ec31dcd4387b12c3089a5616d0189b6c1
DEBUG [1596603704.572] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.573] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.574] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 4096 sortitions (0-4096)
DEBUG [1596603704.606] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 4097
DEBUG [1596603704.607] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (4097-8193)...
DEBUG [1596603704.631] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.633] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 8193 (fca82d7edffc08ad32b974e9dbd79dd7d7a60539)
DEBUG [1596603704.638] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.639] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.641] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (4097-8193)
DEBUG [1596603704.674] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (4096,4097) (was (0,4097))
DEBUG [1596603704.675] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 4096
DEBUG [1596603704.677] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (4096-8192)...
DEBUG [1596603704.704] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.706] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 8192 (fd6142aa94503ef8d22fe295fdb50972ec5388e6)
DEBUG [1596603704.711] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.712] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.714] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 4096 sortitions (4096-8192)
DEBUG [1596603704.746] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 4097
DEBUG [1596603704.748] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (4097-8193)...
DEBUG [1596603704.773] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.775] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 8193 (fca82d7edffc08ad32b974e9dbd79dd7d7a60539)
DEBUG [1596603704.780] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.781] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.782] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (4097-8193)
DEBUG [1596603704.816] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (8192,4097) (was (0,4097))
DEBUG [1596603704.817] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 8192
DEBUG [1596603704.819] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (8192-12288)...
DEBUG [1596603704.844] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.845] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 12288 (923e0fc7fd304bba3e60c7e01bdccccc41ffdfdc)
DEBUG [1596603704.850] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.851] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.853] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 4096 sortitions (8192-12288)
DEBUG [1596603704.886] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 4097
DEBUG [1596603704.887] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (4097-8193)...
DEBUG [1596603704.912] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.913] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 8193 (fca82d7edffc08ad32b974e9dbd79dd7d7a60539)
DEBUG [1596603704.919] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.919] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.921] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (4097-8193)
DEBUG [1596603704.957] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (12288,4097) (was (0,4097))
DEBUG [1596603704.958] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 12288
DEBUG [1596603704.960] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (12288-16384)...
DEBUG [1596603704.984] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603704.985] [src/net/download.rs:542] [ThreadId(7)] Load 1395 headers off of 13683 (62d30d4ac2eb2c883593f2e635209f60aecf52d0)
DEBUG [1596603704.990] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603704.991] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603704.993] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 1395 sortitions (12288-16384)
DEBUG [1596603705.004] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 4097
DEBUG [1596603705.006] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (4097-8193)...
DEBUG [1596603705.031] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603705.033] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 8193 (fca82d7edffc08ad32b974e9dbd79dd7d7a60539)
DEBUG [1596603705.038] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603705.039] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603705.041] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (4097-8193)
DEBUG [1596603705.073] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (13682,4097) (was (0,4097))
DEBUG [1596603705.074] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 13682
DEBUG [1596603705.076] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (13682-17778)...
DEBUG [1596603705.100] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603705.101] [src/net/download.rs:542] [ThreadId(7)] Load 1 headers off of 13683 (62d30d4ac2eb2c883593f2e635209f60aecf52d0)
DEBUG [1596603705.106] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603705.106] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603705.108] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 1 sortitions (13682-17778)
DEBUG [1596603705.108] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 4097
DEBUG [1596603705.109] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (4097-8193)...
DEBUG [1596603705.134] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603705.136] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 8193 (fca82d7edffc08ad32b974e9dbd79dd7d7a60539)
DEBUG [1596603705.141] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603705.142] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603705.143] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): microblocks availability calculated over 4096 sortitions (4097-8193)
DEBUG [1596603705.175] [src/net/download.rs:1029] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): block download scan now at (13682,4097) (was (0,4097))
DEBUG [1596603705.176] [src/net/download.rs:1058] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Will try for 0 blocks and 0 microblocks (next sortition heights are 17778,8193, chain tip is 13683)
DEBUG [1596603705.178] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is DNSLookupFinish
DEBUG [1596603705.178] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetBlocksBegin
DEBUG [1596603705.178] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetBlocksFinish
DEBUG [1596603705.178] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetMicroblocksBegin
DEBUG [1596603705.178] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is GetMicroblocksFinish
DEBUG [1596603705.178] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is Done
DEBUG [1596603705.178] [src/net/download.rs:1307] [ThreadId(7)] Blocks to try: 0; Microblocks to try: 0
DEBUG [1596603705.178] [src/net/download.rs:1312] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Advance downloader to start at sortition heights 17778,8193
DEBUG [1596603705.178] [src/net/download.rs:1317] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Downloader for blocks has reached the chain tip
DEBUG [1596603705.178] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is Prune
DEBUG [1596603705.178] [src/net/neighbors.rs:1447] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): failed to begin inbound neighbor walk: no one's connected to us
DEBUG [1596603705.178] [src/net/neighbors.rs:1991] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Failed to begin neighbor walk from pingback: NoSuchNeighbor
DEBUG [1596603705.178] [src/net/p2p.rs:2800] [ThreadId(7)] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< End Network Dispatch <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
DEBUG [1596603705.178] [testnet/stacks-node/src/neon_node.rs:270] [ThreadId(7)] P2P: backpressure: false, more downloads: true
DEBUG [1596603705.220] [src/chainstate/stacks/db/unconfirmed.rs:249] [ThreadId(7)] Refresh read-only unconfirmed state off of 1fbb872c22053678a468853896f46673f2dc1d43d63832a32936eb1f4258f042
DEBUG [1596603705.221] [src/net/p2p.rs:2773] [ThreadId(7)] >>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for 100) >>>>>>>>>>>>>>>>>>>>>>>>>>>>
DEBUG [1596603705.345] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is GetPublicIP
DEBUG [1596603705.347] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603758
DEBUG [1596603705.348] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is ConfirmPublicIP
DEBUG [1596603705.348] [src/net/p2p.rs:1954] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): throttle public IP request (max retires 4 exceeded) until 1596603758
DEBUG [1596603705.348] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockInvSync
DEBUG [1596603705.348] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvBegin
DEBUG [1596603705.348] [src/net/inv.rs:981] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Will send 0 getblocksinv requests (out of 0 active events)
DEBUG [1596603705.348] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is GetBlocksInvFinish
DEBUG [1596603705.348] [src/net/inv.rs:772] [ThreadId(7)] Still waiting for 0 blocksinv replies
DEBUG [1596603705.348] [src/net/inv.rs:1083] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): inv-sync state is Done
DEBUG [1596603705.348] [src/net/inv.rs:1175] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Advanced inv-sync rescan height to 12288 from 8192
DEBUG [1596603705.348] [src/net/p2p.rs:2170] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): network work state is BlockDownload
DEBUG [1596603705.348] [src/net/download.rs:1428] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Download state is DNSLookupBegin
DEBUG [1596603705.348] [src/net/download.rs:921] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Look for blocks at sortition 0, microblocks at sortition 8193
DEBUG [1596603705.348] [src/net/download.rs:929] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make block requests from sortition height 0
DEBUG [1596603705.348] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find anchored blocks availability over sortitions (0-4096)...
DEBUG [1596603705.388] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603705.390] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 4096 (3f93b440c1544631684e121b7f9fbe35a7d9c91a)
DEBUG [1596603705.396] [src/chainstate/burn/db/sortdb.rs:1208] [ThreadId(7)] CACHE MISS 7d5192af7af3c78263748aff2b529e3ec31dcd4387b12c3089a5616d0189b6c1
DEBUG [1596603705.397] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603705.398] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items
DEBUG [1596603705.399] [src/net/download.rs:730] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): anchored blocks availability calculated over 4096 sortitions (0-4096)
DEBUG [1596603705.429] [src/net/download.rs:932] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Make microblock requests from sortition height 8193
DEBUG [1596603705.431] [src/net/download.rs:724] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): find microblocks availability over sortitions (8193-12289)...
DEBUG [1596603705.456] [src/net/download.rs:538] [ThreadId(7)] Begin headers load
DEBUG [1596603705.458] [src/net/download.rs:542] [ThreadId(7)] Load 4096 headers off of 12289 (1de2c12c18f0dd80f2ebfb064b5b2039c03d80c6)
DEBUG [1596603705.463] [src/net/download.rs:551] [ThreadId(7)] End headers load
DEBUG [1596603705.464] [src/chainstate/burn/db/sortdb.rs:1638] [ThreadId(7)] Block header cache has 13682 items

@psq
Copy link
Contributor

psq commented Aug 8, 2020

Thank you for the additional log @paradigma-cl, nothing strange seems to have happened to thread 6, and thread 1 also stopped processing anything.

Looks like the root cause may be that Argon just stopped answering:

DEBUG [1596603698.276] [src/net/neighbors.rs:542] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Failed to get Handshake reply from facade01+80000000://V4(35.245.47.179:20444): RecvTimeout
DEBUG [1596603698.276] [src/net/connection.rs:1120] [ThreadId(7)] Request timed out: seq=955784534 ttl=1596603694 now=1596603698
DEBUG [1596603698.276] [src/net/p2p.rs:1480] [ThreadId(7)] local.80000000://(bind=V4(0.0.0.0:20444))(pub=None): Disconnect unresponsive unauthenticated peer convo:id=706,outbound=true,peer=UNKNOWN+UNKNOWN://V4(35.245.47.179:20444): 1596603664 + 30 < 1596603698
DEBUG [1596603698.276] [src/net/poll.rs:224] [ThreadId(7)] Socket deregistered: 706, TcpStream { addr: V4(192.168.0.13:38410), peer: V4(35.245.47.179:20444), fd: 40 } (Events total: 2, max: 800)

and later on we see a number of

Failed to get Handshake reply from facade01+80000000://V4(35.245.47.179:20444): RecvTimeout
Disconnect unresponsive unauthenticated peer

in the original log, one about every 90s

@jcnelson
Copy link
Member

This may have been caused by this weekend's testnet outage. Does the problem persist?

@paradigma-cl
Copy link
Author

Problem persists @jcnelson , with a different floor value.
Here are the last balances from last night to now
{"balance":0.285325}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.271465}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.135385}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}

I guess as @psq mentioned, that the values of BTC left after the mining, are no usable after some time.

@psq
Copy link
Contributor

psq commented Aug 12, 2020

listunspent times out on your address after a minute, and most likely, you don't have anything usable, so I would generate a new address and start using it.

@paradigma-cl
Copy link
Author

@psq Probably it is that, but I think that the equivalent of USD 1200 still is "some" money. So how to prevent that the expenditure gets transformed to smoke? Originally started with 0.5 BTC and goes down to 20% of that value. Is that how it works in general in the bitcoin mining?

@psq
Copy link
Contributor

psq commented Aug 13, 2020

@paradigma-cl agreed, and that's fixable, and will get addressed one way or an other. There are some thoughts at #1783 and preferably implementing #1615 would also take care of it.

@jcnelson
Copy link
Member

This may a dup of #1783. The bitcoin node used by Argon just isn't that fast -- it takes a long time for it to reply all of the UTXOs to your miner node if you have used the same key to mine blocks for a long time. I get a timeout when I run bitcoin-cli -rpcconnect=35.221.35.47 -rpcport=18443 listunspent 0 20000 '["n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo"]'.

@psq
Copy link
Contributor

psq commented Aug 13, 2020

@jcnelson as a temporary fix, we could set the amount used in the key registration to 11_000 (I think that's the amount used for commits, or whatever that amount is) and change list_unspent to return the smallest UTXO greater or equal than minimum_sum_amount instead of the first one that is larger, this would avoid leaving all these UTXOs with an unusable amount as the code is not going to use multiple UTXOs in one tx.

Happy to create a PR for this if you think this could work.

in the case of #1783, it was not timing out, just taking enough time to skip a block. If there's 0.1 BTC left, these would mean @paradigma-cl mined over 1_800 blocks and no UTXO is greater than 5_500.

@timstackblock
Copy link
Contributor

@paradigma-cl thank you for the submission 👍

@timstackblock
Copy link
Contributor

@paradigma-cl
Were we able to reproduce this issue?

@timstackblock
Copy link
Contributor

@paradigma-cl any update on if this issue is reproducible?

@paradigma-cl
Copy link
Author

This week I managed to reach again the floor amount of BTC's that a miner can use for registering blocks "balance":0.103885 Then the miner looks likes that stops registering the blocks. 1/5 of the initial amount loaded by the faucet. It should at least get close to 0.

"balance":0.35552}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.299185}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.29168}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.15665}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.15665}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"error":"[object Object]","errorTag":"17900f6f-2ae3-483e-b692-81dce3eda140"}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.156595}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.120475}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.1199}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.119845}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.115435}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:
$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:$ curl https://sidecar.staging.blockstack.xyz/sidecar/v1/faucets/btc/n3WmGv1fgjt8eMcCJuV21QNqgjTHnP9DBo
{"balance":0.103885}proe@node:
$

@psq
Copy link
Contributor

psq commented Sep 9, 2020

@paradigma-cl once this PR (#1848) is live on Krypton, this problem should disappear

@diwakergupta
Copy link
Member

Fixed by #1848 (which addresses #1615 ). Let's reopen or file a new issue as needed once Krypton is live.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Unwanted or unintended property causing functional harm testnet
Projects
None yet
Development

No branches or pull requests

5 participants