Fix importmulti failure to return rescan errors #10403

ryanofsky commented at 1:22 PM on May 15, 2017: member

An off-by-one-block bug in importmulti rescan logic could cause it to return success in an edge case even when a rescan was not successful. The case where this would happen is if there were multiple blocks in a row with the same GetBlockTimeMax() value, and the last block was scanned successfully, but one or more of the earlier blocks was not readable.

This is fixed by changing the CWallet::ScanForWalletTransactions return value to point to the last failed block that could not be rescanned, and then updating the ScanForWalletTransactions call in importmulti to use the new return value.

Fix importmulti failure to return rescan errors

An off-by-one-block bug in importmulti rescan logic could cause it to return
success in an edge case even when a rescan was not successful. The case where
this would happen is if there were multiple blocks in a row with the same
GetBlockTimeMax() value, and the last block was scanned successfully, but one
or more of the earlier blocks was not readable.

4d2d6045a4

fanquake added the label RPC/REST/ZMQ on May 15, 2017

fanquake added the label Wallet on May 15, 2017

ryanofsky force-pushed on May 16, 2017

laanwj added the label Needs backport on May 18, 2017

in src/wallet/rpcdump.cpp:1145 in b4919d0b60 outdated

1142 |                      response.push_back(results.at(i));
1143 |                  } else {
1144 |                      UniValue result = UniValue(UniValue::VOBJ);
1145 |                      result.pushKV("success", UniValue(false));
1146 | -                    result.pushKV("error", JSONRPCError(RPC_MISC_ERROR, strprintf("Failed to rescan before time %d, transactions may be missing.", scannedRange->GetBlockTimeMax())));
1147 | +                    result.pushKV("error", JSONRPCError(RPC_MISC_ERROR, strprintf("Failed to rescan before time %d, transactions may be missing.", scanFailed->GetBlockTimeMax() + 1)));

laanwj commented at 2:06 PM on May 22, 2017:

As it scans forward (increasing date / block numbers), and scanFailed returns the first block that could not be scanned, shouldn't this be "after time"?

ryanofsky commented at 2:34 PM on May 22, 2017:

As it scans forward (increasing date / block numbers), and scanFailed returns the first block that could not be scanned, shouldn't this be "after time"?

scanFailed returns the last block that could not be scanned, not the first block that couldn't be scanned. To take a concrete example, say there are two blocks in a row with GetBlockTimeMax() == 1000, and the first block fails to scan, and the second block succeeds, and later blocks also succeed. If there are any keys created at time 1000 or earlier, there could be transactions missing that pertain to those keys, so those keys should return errors. If there are any keys created at time 1001 or higher, they should technically be ok (even though they will still return errors for birthdays up to 1000 + TIMESTAMP_WINDOW).

The error returned for the problem keys will be "Failed to rescan before time 1001, transactions may be missing." which I think makes sense if "before" implies "less than" rather than "less than or equal".

jnewbery commented at 11:10 PM on May 22, 2017:

I spent some time thinking about edge cases here, and I've basically convinced myself that this is ok, because:

the TIMESTAMP_WINDOW means that we have a good safety window between the address's birthday and the block timestamp (ie we're safe even if an address appears in a block with a timestamp before its birthday).
the monotonically increasing GetBlockTimeMax() means that this error message gives the most conservative value (ie if a block B's time has moved back from its parent block A and we couldn't scan block B then the error will say that we couldn't scan before Block A's timestamp. That's fine)

I think it might be useful for the user if there was a bit more information in the error message. Up to you how verbose you want to go, but a couple of things that might be good to include:

how does the user fix this problem (reindex, which will cause a full chain download if this is a pruning node)
what if the Failed to rescan before time <time> is for a time before the user specified as the address birthday? eg what if the user set the birthday to 10am, and we failed to scan a block at 9:55am. We'd return an error saying Failed to rescan before time 9:55am and the user might thing "that's ok, my key's birthday is 10am". In fact it's not ok, because the 9:55am block may include a transaction for that address, since block time is not canonical or monotonic.

ryanofsky commented at 1:13 PM on May 23, 2017:

Thanks, expanded error message in 2e041dd247c19a47700b1e1b181c7f8a1b5b109b

in src/wallet/rpcdump.cpp:1140 in b4919d0b60 outdated

1136 | @@ -1137,12 +1137,12 @@ UniValue importmulti(const JSONRPCRequest& mainRequest)
1137 |                  // range, or if the import result already has an error set, let
1138 |                  // the result stand unmodified. Otherwise replace the result
1139 |                  // with an error message.
1140 | -                if (GetImportTimestamp(request, now) - TIMESTAMP_WINDOW >= scannedRange->GetBlockTimeMax() || results.at(i).exists("error")) {
1141 | +                if (GetImportTimestamp(request, now) - TIMESTAMP_WINDOW > scanFailed->GetBlockTimeMax() || results.at(i).exists("error")) {

laanwj commented at 2:17 PM on May 22, 2017:

So this checks that the birthday of the imported key is after most recent block that could not be scanned, in which case the current result will be returned? This seems to disagree with the comment "key creation date is within the successfully scanned range". What am I misunderstanding here?

ryanofsky commented at 2:46 PM on May 22, 2017:

So this checks that the birthday of the imported key is after most recent block that could not be scanned, in which case the current result will be returned?

Yes, if the key birthday is after the GetBlockTimeMax of the most recent block that could not be scanned + TIMESTAMP_WINDOW, the rescan for that key's transactions is considered successful, and the result is not replaced.

This seems to disagree with the comment "key creation date is within the successfully scanned range". What am I misunderstanding here?

I may be misunderstanding something, but the comment seems right to me. If the most recent block that could not be scanned has GetBlockTimeMax == 1000, then any key created at timestamp 1001 or higher is in the "successfully scanned range", because all the blocks that were bad or missing are older than the key, and therefore not relevant.

laanwj commented at 10:56 AM on May 24, 2017:

because all the blocks that were bad or missing are older than the key, and therefore not relevant.

That's the part I'm not sure about: aren't the blocks at and after that point missing, instead of before that point? After all it's the point where it failed in a linear forward scan?

ryanofsky commented at 11:46 AM on May 24, 2017:

That's the part I'm not sure about: aren't the blocks at and after that point missing, instead of before that point?

Because it returns a pointer to the last block that couldn't be scanned, it means that any blocks after the pointer were scanned successfully.

After all it's the point where it failed in a linear forward scan?

The scan does keep going even if individual blocks couldn't be read. There might be a smarter way to handle this, but the behavior has been around a while. Only the error reporting is fairly new.

ryanofsky force-pushed on May 23, 2017

ryanofsky commented at 1:17 PM on May 23, 2017: member

Squashed 2e041dd247c19a47700b1e1b181c7f8a1b5b109b -> 4d2d6045a4784d576d56299244b9f76a5909904b (pr/scansame.3 -> pr/scansame.4)

jnewbery commented at 1:52 PM on May 23, 2017: member

Looks good. Tested ACK https://github.com/bitcoin/bitcoin/commit/2e041dd247c19a47700b1e1b181c7f8a1b5b109b. It'd be nice to have tests covering the edge cases (block time the same for two consecutive blocks and block time decreasing), but that can be left for a future PR.

jonasschnelli commented at 6:51 AM on May 24, 2017: contributor

utACK 4d2d6045a4784d576d56299244b9f76a5909904b Very verbose error description texts (but great explanation).

laanwj commented at 2:40 PM on June 5, 2017: member

utACK 4d2d604

laanwj merged this on Jun 5, 2017

laanwj closed this on Jun 5, 2017

laanwj referenced this in commit 08d0390a5f on Jun 5, 2017

laanwj added this to the milestone 0.14.3 on Sep 5, 2017

fanquake removed the label Needs backport on Mar 7, 2018

PastaPastaPasta referenced this in commit c76f713d13 on Jun 20, 2019

PastaPastaPasta referenced this in commit 6a7f4edad9 on Jun 22, 2019

PastaPastaPasta referenced this in commit 0488cfcaa4 on Jun 22, 2019

PastaPastaPasta referenced this in commit ace3c71bc1 on Jun 22, 2019

PastaPastaPasta referenced this in commit bd57f61bb2 on Jun 22, 2019

PastaPastaPasta referenced this in commit 8cb46d6f0e on Jun 22, 2019

PastaPastaPasta referenced this in commit 8420e1877e on Jun 22, 2019

PastaPastaPasta referenced this in commit 329ab1bbee on Jun 22, 2019

PastaPastaPasta referenced this in commit c0ef2f6f3c on Jun 22, 2019

PastaPastaPasta referenced this in commit 125317a753 on Jun 22, 2019

PastaPastaPasta referenced this in commit fd088a8756 on Jun 22, 2019

PastaPastaPasta referenced this in commit 51525efd66 on Jun 26, 2019

barrystyle referenced this in commit d947be2110 on Jan 22, 2020

DrahtBot locked this on Sep 8, 2021