BDK keychain tracker gets wiped after processing empty update

[benthecarman]

Describe the bug
The bdk keychain tracker will get wiped when we do a sync that does not have any updates (no new or updated txs). This makes it so we need to do a full sync every time the wallet is opened and wastes a lot of resources.

Build environment

• BDK tag/commit: bdk alpha1
• OS+version: wasm
• Rust/Cargo version: nightly
• Rust/Cargo target: wasm32-unknown-unknown

Additional context

this happened with our previous full sync and the new just checking unused addresses sync

[evanlinjin]

Just to confirm, are you sure this is a bug for alpha.1? There is no longer a "keychain tracker" for alpha.1. Do you mean alpha.0?

This should not be a problem for alpha.1. Empty updates should do nothing to LocalChain and TxGraph.

[benthecarman]

This is alpha 1. I'm not sure what things are called but whatever we have to persist, gets emptied

[evanlinjin]

Would you be able to provide a bit more detail?

How are you using the library - which methods are you calling? Maybe some steps for reproducing? Even showing how we can reproduce the issue with mutiny-node will go a long way.

Thanks in advance.

[benthecarman]

This is our syncing logic https://github.com/MutinyWallet/mutiny-node/blob/master/mutiny-core/src/onchain.rs#L93

This is how we do storage https://github.com/MutinyWallet/mutiny-node/blob/master/mutiny-core/src/storage.rs#L564

To reproduce in mutiny, create a wallet, send on-chain, wait for a new block to sync, restart mutiny and it'll have 0 balance until it syncs again

[LLFourn]

Hey @benthecarman. Could you tell us whether there is any data in the database when you read it in and you get 0 balance. E.g. you could run through the issue reproduction and just println the JSON object when it is written and read through the process. We weren't sure the exact steps for compiling and running mutiny but I guess it will be faster if you do this for us.

There are two possible explanations that I can think of:

1. Persistence backend is not loading from the same place it saved to or is not saving it properly.
2. The changes in your derivation index of your wallet's keychian is not being written somehow so even thought the tx data is there wallet won't find it (this would be a bug in Wallet).

[benthecarman]

Could you tell us whether there is any data in the database when you read it in and you get 0 balance. E.g. you could run through the issue reproduction and just println the JSON object when it is written and read through the process.

Can do

[benthecarman]

{
  "chain_changeset": {
    "306879": "00000103bf2e590cd1103392d397b885e326e7a76ca9bd258c68a550db5e2d08"
  },
  "indexed_additions": {
    "graph_additions": {
      "anchors": [
        [
          {
            "anchor_block": {
              "hash": "00000103bf2e590cd1103392d397b885e326e7a76ca9bd258c68a550db5e2d08",
              "height": 306879
            },
            "confirmation_height": 297446,
            "confirmation_time": 1691182925
          },
          "1d3df203b1308d7d1bb03ad43f49ab23e202766f4db19d5a2c98b19db97c7d73"
        ]
      ],
      "last_seen": {},
      "txouts": {},
      "txs": []
    },
    "index_additions": {
    }
  }
}

[LLFourn]

So the most likely explanation here is that you are fully writing over the original changeset with the new one (rather than merging them). The logic in your code doesn't look like you do that but the result is indeed that somehow.

Can you dump us the following before doing the commit that gives you that db state:

1. Dump the database JSON
2. println!("{:?}", wallet.tx_graph().initial_changeset()) <-- before apply thing the update (this should show the same thing as in the database JSON).
3. println!("{:?}", update) <-- the update you are going to apply
4. prinlnt!("{:?}", wallet.staged()) <-- after applying the update but not doing .commit().

Thanks!

[benthecarman]

1: Dump the database: Some(Object {"chain_changeset": Object {"307114": String("000001ec8dc84d0ceab8f40c9bab8c0ce667f33c8198b863864170e8a9107fac")}, "indexed_additions": Object {"graph_additions": Object {"anchors": Array [Array [Object {"anchor_block": Object {"hash": String("000001ec8dc84d0ceab8f40c9bab8c0ce667f33c8198b863864170e8a9107fac"), "height": Number(307114)}, "confirmation_height": Number(297446), "confirmation_time": Number(1691182925)}, String("1d3df203b1308d7d1bb03ad43f49ab23e202766f4db19d5a2c98b19db97c7d73")]], "last_seen": Object {}, "txouts": Object {}, "txs": Array []}, "index_additions": Object {}}})
2: initial_changeset() isn't a function? skipped
3. update: LocalUpdate { keychain: {External: 0}, graph: TxGraph { txs: {1d3df203b1308d7d1bb03ad43f49ab23e202766f4db19d5a2c98b19db97c7d73: (Whole(Transaction { version: 2, lock_time: PackedLockTime(297444), input: [TxIn { previous_output: OutPoint { txid: d605905d1a6f6a2a5af0d19bd1d5917cd7de8b41e404e8fe18e518c83ec5a5e8, vout: 0 }, script_sig: Script(), sequence: Sequence(4294967293), witness: Witness { content: [71, 48, 68, 2, 32, 70, 66, 128, 134, 131, 165, 161, 8, 184, 151, 67, 146, 156, 100, 167, 250, 103, 73, 119, 165, 120, 248, 248, 93, 152, 44, 115, 254, 5, 0, 206, 111, 2, 32, 116, 53, 182, 80, 105, 241, 179, 96, 224, 102, 217, 68, 42, 17, 247, 33, 228, 88, 4, 54, 109, 61, 13, 159, 114, 251, 137, 246, 105, 76, 224, 199, 1, 33, 2, 250, 137, 164, 184, 12, 118, 37, 97, 108, 57, 233, 202, 237, 149, 79, 254, 116, 48, 213, 12, 30, 133, 136, 104, 231, 126, 9, 30, 126, 51, 243, 83], witness_elements: 2, last: 72, second_to_last: 0 } }], output: [TxOut { value: 2499896940, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 84c4d6b9c895ae2add3c728e550e6f0460dca078) }, TxOut { value: 100000, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 3c95774869b5401519e37b2ac840d3ab042090ceee5232b3f9c01aab85b1185c) }] }), {ConfirmationTimeAnchor { anchor_block: BlockId { height: 307111, hash: 000000c3b15904147c47adcbe4968833c78b39508209badbc0cf4876a03e3877 }, confirmation_height: 297446, confirmation_time: 1691182925 }}, 0)}, spends: {OutPoint { txid: d605905d1a6f6a2a5af0d19bd1d5917cd7de8b41e404e8fe18e518c83ec5a5e8, vout: 0 }: {1d3df203b1308d7d1bb03ad43f49ab23e202766f4db19d5a2c98b19db97c7d73}}, anchors: {(ConfirmationTimeAnchor { anchor_block: BlockId { height: 307111, hash: 000000c3b15904147c47adcbe4968833c78b39508209badbc0cf4876a03e3877 }, confirmation_height: 297446, confirmation_time: 1691182925 }, 1d3df203b1308d7d1bb03ad43f49ab23e202766f4db19d5a2c98b19db97c7d73)}, empty_outspends: {} }, chain: LocalChain { blocks: {307109: 00000330534ce757418655afa34206d3294503ccafb16037f0733b0f9940f5f2, 307111: 000000c3b15904147c47adcbe4968833c78b39508209badbc0cf4876a03e3877} } }
4. staged: LocalChangeSet { chain_changeset: {307111: Some(000000c3b15904147c47adcbe4968833c78b39508209badbc0cf4876a03e3877)}, indexed_additions: IndexedAdditions { graph_additions: Additions { txs: {Transaction { version: 2, lock_time: PackedLockTime(297444), input: [TxIn { previous_output: OutPoint { txid: d605905d1a6f6a2a5af0d19bd1d5917cd7de8b41e404e8fe18e518c83ec5a5e8, vout: 0 }, script_sig: Script(), sequence: Sequence(4294967293), witness: Witness { content: [71, 48, 68, 2, 32, 70, 66, 128, 134, 131, 165, 161, 8, 184, 151, 67, 146, 156, 100, 167, 250, 103, 73, 119, 165, 120, 248, 248, 93, 152, 44, 115, 254, 5, 0, 206, 111, 2, 32, 116, 53, 182, 80, 105, 241, 179, 96, 224, 102, 217, 68, 42, 17, 247, 33, 228, 88, 4, 54, 109, 61, 13, 159, 114, 251, 137, 246, 105, 76, 224, 199, 1, 33, 2, 250, 137, 164, 184, 12, 118, 37, 97, 108, 57, 233, 202, 237, 149, 79, 254, 116, 48, 213, 12, 30, 133, 136, 104, 231, 126, 9, 30, 126, 51, 243, 83], witness_elements: 2, last: 72, second_to_last: 0 } }], output: [TxOut { value: 2499896940, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 84c4d6b9c895ae2add3c728e550e6f0460dca078) }, TxOut { value: 100000, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 3c95774869b5401519e37b2ac840d3ab042090ceee5232b3f9c01aab85b1185c) }] }}, txouts: {}, anchors: {(ConfirmationTimeAnchor { anchor_block: BlockId { height: 307111, hash: 000000c3b15904147c47adcbe4968833c78b39508209badbc0cf4876a03e3877 }, confirmation_height: 297446, confirmation_time: 1691182925 }, 1d3df203b1308d7d1bb03ad43f49ab23e202766f4db19d5a2c98b19db97c7d73)}, last_seen: {} }, index_additions: DerivationAdditions({External: 0}) } }

[benthecarman]

Hmm might have found the bug on our end, we would remove the bdk store from our in memory cache after it was read, removing that seemed to fix

[benthecarman]

Okay was able to figure out our issue, thanks for the help!

MutinyWallet/mutiny-node#698

[LLFourn]

Good news. One thing I noted while looking at your implementation that might have made harder to reason about was that you fully read in the existing changeset, append to it and then write it out again for every change. Since it looks like you are working with a key value store, the way we imagined you'd do this is you would insert each changeset separately at a certain key with an index and then at start up do a range query to collect all the changesets within that range and append them altogether. Note that at the moment they have to be stored and appended in the order they came from Wallet (but we might able to remove this requirement #1005).

initial_changeset doesn't exist

oops. My bad.

[benthecarman]

Yeah we could do that, appending all the changes into a single key makes it much simpler for us however.