[RPC][Test] Fix wallet_import_rescan

src/chain.h

@@ -22,6 +22,13 @@
 
 #include <vector>
 
+/**
+ * Timestamp window used as a grace period by code that compares external
+ * timestamps (such as timestamps passed to RPCs, or wallet key creation times)
+ * to block timestamps.
+ */
+static constexpr int64_t TIMESTAMP_WINDOW = 2 * 60 * 60;
+
 class CBlockFileInfo
 {
 public:

src/net.cpp

@@ -823,7 +823,7 @@ size_t CConnman::SocketSendData(CNode* pnode)
             nBytes = send(pnode->hSocket, reinterpret_cast<const char*>(data.data()) + pnode->nSendOffset, data.size() - pnode->nSendOffset, MSG_NOSIGNAL | MSG_DONTWAIT);
         }
         if (nBytes > 0) {
-            pnode->nLastSend = GetTime();
+            pnode->nLastSend = GetSystemTimeInSeconds();
             pnode->nSendBytes += nBytes;
             pnode->nSendOffset += nBytes;
             nSentSize += nBytes;
@@ -1311,7 +1311,7 @@ void CConnman::ThreadSocketHandler()
             //
             // Inactivity checking
             //
-            int64_t nTime = GetTime();
+            int64_t nTime = GetSystemTimeInSeconds();
             if (nTime - pnode->nTimeConnected > 60) {
                 if (pnode->nLastRecv == 0 || pnode->nLastSend == 0) {
                     LogPrint(BCLog::NET, "socket no message in first 60 seconds, %d %d from %d\n", pnode->nLastRecv != 0, pnode->nLastSend != 0, pnode->id);
@@ -2401,7 +2401,7 @@ unsigned int CConnman::GetReceiveFloodSize() const { return nReceiveFloodSize; }
 unsigned int CConnman::GetSendBufferSize() const{ return nSendBufferMaxSize; }
 
 CNode::CNode(NodeId idIn, ServiceFlags nLocalServicesIn, int nMyStartingHeightIn, SOCKET hSocketIn, const CAddress& addrIn, uint64_t nKeyedNetGroupIn, uint64_t nLocalHostNonceIn, const std::string& addrNameIn, bool fInboundIn) :
-    nTimeConnected(GetTime()),
+    nTimeConnected(GetSystemTimeInSeconds()),
     addr(addrIn),
     fInbound(fInboundIn),
     id(idIn),

src/qt/rpcconsole.cpp

@@ -901,11 +901,11 @@ void RPCConsole::updateNodeDetail(const CNodeCombinedStats* stats)
         peerAddrDetails += "<br />" + tr("via %1").arg(QString::fromStdString(stats->nodeStats.addrLocal));
     ui->peerHeading->setText(peerAddrDetails);
     ui->peerServices->setText(GUIUtil::formatServicesStr(stats->nodeStats.nServices));
-    ui->peerLastSend->setText(stats->nodeStats.nLastSend ? GUIUtil::formatDurationStr(GetTime() - stats->nodeStats.nLastSend) : tr("never"));
-    ui->peerLastRecv->setText(stats->nodeStats.nLastRecv ? GUIUtil::formatDurationStr(GetTime() - stats->nodeStats.nLastRecv) : tr("never"));
+    ui->peerLastSend->setText(stats->nodeStats.nLastSend ? GUIUtil::formatDurationStr(GetSystemTimeInSeconds() - stats->nodeStats.nLastSend) : tr("never"));
+    ui->peerLastRecv->setText(stats->nodeStats.nLastRecv ? GUIUtil::formatDurationStr(GetSystemTimeInSeconds() - stats->nodeStats.nLastRecv) : tr("never"));
     ui->peerBytesSent->setText(FormatBytes(stats->nodeStats.nSendBytes));
     ui->peerBytesRecv->setText(FormatBytes(stats->nodeStats.nRecvBytes));
-    ui->peerConnTime->setText(GUIUtil::formatDurationStr(GetTime() - stats->nodeStats.nTimeConnected));
+    ui->peerConnTime->setText(GUIUtil::formatDurationStr(GetSystemTimeInSeconds() - stats->nodeStats.nTimeConnected));
     ui->peerPingTime->setText(GUIUtil::formatPingTime(stats->nodeStats.dPingTime));
     ui->peerPingWait->setText(GUIUtil::formatPingTime(stats->nodeStats.dPingWait));
     ui->timeoffset->setText(GUIUtil::formatTimeOffset(stats->nodeStats.nTimeOffset));

src/rpc/misc.cpp

@@ -607,18 +607,16 @@ UniValue setmocktime(const JSONRPCRequest& request)
     if (!Params().IsRegTestNet())
         throw std::runtime_error("setmocktime for regression testing (-regtest mode) only");
 
+    // For now, don't change mocktime if we're in the middle of validation, as
+    // this could have an effect on mempool time-based eviction, as well as
+    // IsCurrentForFeeEstimation() and IsInitialBlockDownload().
+    // TODO: figure out the right way to synchronize around mocktime, and
+    // ensure all callsites of GetTime() are accessing this safely.
     LOCK(cs_main);
 
     RPCTypeCheck(request.params, {UniValue::VNUM});
     SetMockTime(request.params[0].get_int64());
 
-    uint64_t t = GetTime();
-    if(g_connman) {
-        g_connman->ForEachNode([t](CNode* pnode) {
-            pnode->nLastSend = pnode->nLastRecv = t;
-        });
-    }
-
     return NullUniValue;
 }
 

src/utiltime.cpp

@@ -43,6 +43,11 @@ int64_t GetTimeMillis()
     return now;
 }
 
+int64_t GetSystemTimeInSeconds()
+{
+    return GetTimeMicros()/1000000;
+}
+
 int64_t GetTimeMicros()
 {
     int64_t now = (boost::posix_time::microsec_clock::universal_time() -

src/utiltime.h

@@ -10,9 +10,20 @@
 #include <stdint.h>
 #include <string>
 
+/**
+ * GetTimeMicros() and GetTimeMillis() both return the system time, but in
+ * different units. GetTime() returns the sytem time in seconds, but also
+ * supports mocktime, where the time can be specified by the user, eg for
+ * testing (eg with the setmocktime rpc, or -mocktime argument).
+ *
+ * TODO: Rework these functions to be type-safe (so that we don't inadvertently
+ * compare numbers with different units, or compare a mocktime to system time).
+ */
+
 int64_t GetTime();
 int64_t GetTimeMillis();
 int64_t GetTimeMicros();
+int64_t GetSystemTimeInSeconds(); // Like GetTime(), but not mockable
 void SetMockTime(int64_t nMockTimeIn);
 void MilliSleep(int64_t n);
 

src/validation.cpp

@@ -4161,6 +4161,11 @@ std::string CBlockFileInfo::ToString() const
     return strprintf("CBlockFileInfo(blocks=%u, size=%u, heights=%u...%u, time=%s...%s)", nBlocks, nSize, nHeightFirst, nHeightLast, DateTimeStrFormat("%Y-%m-%d", nTimeFirst), DateTimeStrFormat("%Y-%m-%d", nTimeLast));
 }
 
+CBlockFileInfo* GetBlockFileInfo(size_t n)
+{
+    return &vinfoBlockFile.at(n);
+}
+
 static const uint64_t MEMPOOL_DUMP_VERSION = 1;
 
 bool LoadMempool(CTxMemPool& pool)

src/validation.h

@@ -401,6 +401,9 @@ static const unsigned int REJECT_ALREADY_KNOWN = 0x101;
 /** Transaction conflicts with a transaction already known */
 static const unsigned int REJECT_CONFLICT = 0x102;
 
+/** Get block file info entry for one block file */
+CBlockFileInfo* GetBlockFileInfo(size_t n);
+
 /** Dump the mempool to disk. */
 bool DumpMempool(const CTxMemPool& pool);
 

src/wallet/rpcdump.cpp

@@ -413,7 +413,7 @@ UniValue importwallet(const JSONRPCRequest& request)
     pwalletMain->ShowProgress("", 100); // hide progress dialog in GUI
 
     CBlockIndex* pindex = chainActive.Tip();
-    while (pindex && pindex->pprev && pindex->GetBlockTime() > nTimeBegin - 7200)
+    while (pindex && pindex->pprev && pindex->GetBlockTime() > nTimeBegin - TIMESTAMP_WINDOW)
         pindex = pindex->pprev;
 
     if (!pwalletMain->nTimeFirstKey || nTimeBegin < pwalletMain->nTimeFirstKey)
@@ -933,13 +933,18 @@ UniValue importmulti(const JSONRPCRequest& mainRequest)
             "  [     (array of json objects)\n"
             "    {\n"
             "      \"scriptPubKey\": \"script\" | { \"address\":\"address\" }, (string / JSON, required) Type of scriptPubKey (string for script, json for address)\n"
+            "      \"timestamp\": timestamp | \"now\"                      (integer / string, required) Creation time of the key in seconds since epoch (Jan 1 1970 GMT),\n"
+            "                                                                 or the string \"now\" to substitute the current synced blockchain time. The timestamp of the oldest\n"
+            "                                                                 key will determine how far back blockchain rescans need to begin for missing wallet transactions.\n"
+            "                                                                 \"now\" can be specified to bypass scanning, for keys which are known to never have been used, and\n"
+            "                                                                 0 can be specified to scan the entire blockchain. Blocks up to 2 hours before the earliest key\n"
+            "                                                                 creation time of all keys being imported by the importmulti call will be scanned.\n"
             "      \"redeemscript\": \"script\",                           (string, optional) Allowed only if the scriptPubKey is a P2SH address or a P2SH scriptPubKey\n"
             "      \"pubkeys\": [\"pubKey\", ... ],                        (array, optional) Array of strings giving pubkeys that must occur in the output or redeemscript\n"
             "      \"keys\": [\"key\", ... ],                              (array, optional) Array of strings giving private keys whose corresponding public keys must occur in the output or redeemscript\n"
             "      \"internal\": true|false,                               (boolean, optional, default: false) Stating whether matching outputs should be be treated as not incoming payments\n"
             "      \"watchonly\": true|false,                              (boolean, optional, default: false) Stating whether matching outputs should be considered watched even when they're not spendable, only allowed if keys are empty\n"
             "      \"label\": label,                                       (string, optional, default: '') Label to assign to the address, only allowed with internal=false\n"
-            "      \"timestamp\": 1454686740,                              (integer, optional, default now) Timestamp\n"
             "    }\n"
             "  ,...\n"
             "  ]\n"
@@ -1023,12 +1028,43 @@ UniValue importmulti(const JSONRPCRequest& mainRequest)
     }
 
     if (fRescan && fRunScan && requests.size() && nLowestTimestamp <= chainActive.Tip()->GetBlockTimeMax()) {
-        CBlockIndex* pindex = nLowestTimestamp > minimumTimestamp ? chainActive.FindEarliestAtLeast(nLowestTimestamp) : chainActive.Genesis();
-
+        CBlockIndex* pindex = nLowestTimestamp > minimumTimestamp ? chainActive.FindEarliestAtLeast(std::max<int64_t>(nLowestTimestamp - TIMESTAMP_WINDOW, 0))
+                                                                  : chainActive.Genesis();
+        CBlockIndex* scanFailed = nullptr;
         if (pindex) {
-            pwalletMain->ScanForWalletTransactions(pindex, nullptr, true);
+            scanFailed = pwalletMain->ScanForWalletTransactions(pindex, nullptr, true);
             pwalletMain->ReacceptWalletTransactions();
         }
+
+        if (scanFailed) {
+            const std::vector<UniValue>& results = response.getValues();
+            response.clear();
+            response.setArray();
+            size_t i = 0;
+            for (const UniValue& request : requests.getValues()) {
+                // If key creation date is within the successfully scanned
+                // range, or if the import result already has an error set, let
+                // the result stand unmodified. Otherwise replace the result
+                // with an error message.
+                if (GetImportTimestamp(request, now) - TIMESTAMP_WINDOW >= scanFailed->GetBlockTimeMax() || results.at(i).exists("error")) {
+                    response.push_back(results.at(i));
+                } else {
+                    UniValue result = UniValue(UniValue::VOBJ);
+                    result.pushKV("success", UniValue(false));
+                    result.pushKV("error", JSONRPCError(RPC_MISC_ERROR,
+                                                strprintf("Rescan failed for key with creation timestamp %d. There was an error reading a "
+                                                          "block from time %d, which is after or within %d seconds of key creation, and "
+                                                          "could contain transactions pertaining to the key. As a result, transactions "
+                                                          "and coins using this key may not appear in the wallet. This error could be "
+                                                          "caused by pruning or data corruption (see pivxd log for details) and could "
+                                                          "be dealt with by downloading and rescanning the relevant blocks (see -reindex "
+                                                          "and -rescan options).",
+                                                          GetImportTimestamp(request, now), scanFailed->GetBlockTimeMax(), TIMESTAMP_WINDOW)));
+                    response.push_back(std::move(result));
+                }
+                ++i;
+            }
+        }
     }
 
     return response;

src/wallet/test/wallet_tests.cpp

@@ -6,6 +6,7 @@
 #include "wallet/test/wallet_test_fixture.h"
 
 #include "consensus/merkle.h"
+#include "rpc/server.h"
 #include "txmempool.h"
 #include "validation.h"
 #include "wallet/wallet.h"
@@ -15,6 +16,12 @@
 #include <vector>
 
 #include <boost/test/unit_test.hpp>
+#include <univalue.h>
+
+extern UniValue importmulti(const JSONRPCRequest& request);
+extern UniValue dumpwallet(const JSONRPCRequest& request);
+extern UniValue importwallet(const JSONRPCRequest& request);
+
 
 // how many times to run all the tests to have a chance to catch errors that only show up with particular random shuffles
 #define RUN_TESTS 100
@@ -306,6 +313,142 @@ BOOST_AUTO_TEST_CASE(coin_selection_tests)
     empty_wallet();
 }
 
+static void AddKey(CWallet& wallet, const CKey& key)
+{
+    LOCK(wallet.cs_wallet);
+    wallet.AddKeyPubKey(key, key.GetPubKey());
+}
+
+BOOST_FIXTURE_TEST_CASE(rescan, TestChain100Setup)
+{
+    // Cap last block file size, and mine new block in a new block file.
+    CBlockIndex* const nullBlock = nullptr;
+    CBlockIndex* oldTip = chainActive.Tip();
+    GetBlockFileInfo(oldTip->GetBlockPos().nFile)->nSize = MAX_BLOCKFILE_SIZE;
+    CreateAndProcessBlock({}, GetScriptForRawPubKey(coinbaseKey.GetPubKey()));
+    CBlockIndex* newTip = chainActive.Tip();
+
+    LOCK(cs_main);
+
+    // Verify ScanForWalletTransactions picks up transactions in both the old
+    // and new block files.
+    {
+        CWallet wallet;
+        WITH_LOCK(wallet.cs_wallet, wallet.SetLastBlockProcessed(newTip); );
+        AddKey(wallet, coinbaseKey);
+        BOOST_CHECK_EQUAL(nullBlock, wallet.ScanForWalletTransactions(oldTip, nullptr));
+        BOOST_CHECK_EQUAL(wallet.GetImmatureBalance(), 500 * COIN);
+    }
+
+    // !TODO: Prune the older block file.
+    /*
+    PruneOneBlockFile(oldTip->GetBlockPos().nFile);
+    UnlinkPrunedFiles({oldTip->GetBlockPos().nFile});
+
+    // Verify ScanForWalletTransactions only picks transactions in the new block
+    // file.
+    {
+        CWallet wallet;
+        AddKey(wallet, coinbaseKey);
+        BOOST_CHECK_EQUAL(oldTip, wallet.ScanForWalletTransactions(oldTip, nullptr));
+        BOOST_CHECK_EQUAL(wallet.GetImmatureBalance(), 50 * COIN);
+    }
+    */
+
+    // Verify importmulti RPC returns failure for a key whose creation time is
+    // before the missing block, and success for a key whose creation time is
+    // after.
+    {
+        CWallet wallet;
+        WITH_LOCK(wallet.cs_wallet, wallet.SetLastBlockProcessed(newTip); );
+        CWallet *backup = ::pwalletMain;
+        ::pwalletMain = &wallet;
+        UniValue keys;
+        keys.setArray();
+        UniValue key;
+        key.setObject();
+        key.pushKV("scriptPubKey", HexStr(GetScriptForRawPubKey(coinbaseKey.GetPubKey())));
+        key.pushKV("timestamp", 0);
+        key.pushKV("internal", UniValue(true));
+        keys.push_back(key);
+        key.clear();
+        key.setObject();
+        CKey futureKey;
+        futureKey.MakeNewKey(true);
+        key.pushKV("scriptPubKey", HexStr(GetScriptForRawPubKey(futureKey.GetPubKey())));
+        key.pushKV("timestamp", newTip->GetBlockTimeMax() + TIMESTAMP_WINDOW + 1);
+        key.pushKV("internal", UniValue(true));
+        keys.push_back(key);
+        JSONRPCRequest request;
+        request.params.setArray();
+        request.params.push_back(keys);
+
+        UniValue response = importmulti(request);
+        // !TODO: after pruning, check that the rescan for the first key fails.
+        BOOST_CHECK_EQUAL(response.write(), "[{\"success\":true},{\"success\":true}]");
+        ::pwalletMain = backup;
+    }
+}
+
+// Verify importwallet RPC starts rescan at earliest block with timestamp
+// greater or equal than key birthday. Previously there was a bug where
+// importwallet RPC would start the scan at the latest block with timestamp less
+// than or equal to key birthday.
+BOOST_FIXTURE_TEST_CASE(importwallet_rescan, TestChain100Setup)
+{
+    CWallet *pwalletMainBackup = ::pwalletMain;
+    // Create one block
+    const int64_t BLOCK_TIME = chainActive.Tip()->GetBlockTimeMax() + 15;
+    SetMockTime(BLOCK_TIME);
+    coinbaseTxns.emplace_back(*CreateAndProcessBlock({}, GetScriptForRawPubKey(coinbaseKey.GetPubKey())).vtx[0]);
+
+    // Set key birthday to block time increased by the timestamp window, so
+    // rescan will start at the block time.
+    const int64_t KEY_TIME = BLOCK_TIME + TIMESTAMP_WINDOW;
+    SetMockTime(KEY_TIME);
+    coinbaseTxns.emplace_back(*CreateAndProcessBlock({}, GetScriptForRawPubKey(coinbaseKey.GetPubKey())).vtx[0]);
+
+    // Import key into wallet and call dumpwallet to create backup file.
+    {
+        CWallet wallet;
+        {
+            LOCK(wallet.cs_wallet);
+            wallet.mapKeyMetadata[coinbaseKey.GetPubKey().GetID()].nCreateTime = KEY_TIME;
+            wallet.AddKeyPubKey(coinbaseKey, coinbaseKey.GetPubKey());
+        }
+
+        JSONRPCRequest request;
+        request.params.setArray();
+        request.params.push_back((pathTemp / "wallet.backup").string());
+        ::pwalletMain = &wallet;
+        ::dumpwallet(request);
+    }
+
+    // Call importwallet RPC and verify all blocks with timestamps >= BLOCK_TIME
+    // were scanned, and no prior blocks were scanned.
+    {
+        CWallet wallet;
+
+        JSONRPCRequest request;
+        request.params.setArray();
+        request.params.push_back((pathTemp / "wallet.backup").string());
+        ::pwalletMain = &wallet;
+        ::importwallet(request);
+
+        LOCK(wallet.cs_wallet);
+        BOOST_CHECK_EQUAL(wallet.mapWallet.size(), 2);
+        BOOST_CHECK_EQUAL(coinbaseTxns.size(), 102);
+        for (size_t i = 0; i < coinbaseTxns.size(); ++i) {
+            bool found = wallet.GetWalletTx(coinbaseTxns[i].GetHash());
+            bool expected = i >= 100;
+            BOOST_CHECK_EQUAL(found, expected);
+        }
+    }
+
+    SetMockTime(0);
+    ::pwalletMain = pwalletMainBackup;
+}
+
 void removeTxFromMempool(CWalletTx& wtx)
 {
     LOCK(mempool.cs);