Auto merge of #4002 - Eirik0:migration-status-info, r=Eirik0

Add Logging and persist async operation for Sapling migration

Currently zcashd will automatically remove the last async migration operations when it reaches the height where it sends the transactions it just made. This is not in alignment with other async operations, which are not removed until a node is restarted or a user calls `z_getoperationresult`. This PR removes the calls to pop the operations so that they can be accessed and reviewed later. In this PR I also correct the operation's `amount_migrated` field to exclude the transaction fee (this field existed for debugging purposes, but should be consistent with `z_getmigrationstatus`), and have included the list of migration txids in the operation's result (this is similar to the async rpcs such as `z_sendmany`).

Documentation: none needed.

Test plan:
* After migration transactions have been created, list the opids and call `z_getoperationresult` on them.
* Check that the operations' `amount_migrated` fields exclude the fee.

qa/rpc-tests/sprout_sapling_migration.py

@@ -45,9 +45,10 @@ class SproutSaplingMigration(BitcoinTestFramework):
         # Add migration parameters to nodes[0]
         extra_args[0] = extra_args[0] + [
             '-migration',
-            '-migrationdestaddress=' + SAPLING_ADDR
+            '-migrationdestaddress=' + SAPLING_ADDR,
+            '-debug=zrpcunsafe'
         ]
-        assert_equal(4, len(extra_args[0]))
+        assert_equal(5, len(extra_args[0]))
         assert_equal(2, len(extra_args[1]))
         return start_nodes(4, self.options.tmpdir, extra_args)
 
@@ -87,6 +88,8 @@ class SproutSaplingMigration(BitcoinTestFramework):
         assert_equal('saplingmigration', result['method'])
         assert_equal(target_height, result['target_height'])
         assert_equal(1, result['result']['num_tx_created'])
+        assert_equal(1, len(result['result']['migration_txids']))
+        assert_true(result['result']['amount_migrated'] > Decimal('0'))
 
         assert_equal(0, len(node.getrawmempool()), "mempool size at 495 % 500")
 

src/wallet/asyncrpcoperation_mergetoaddress.cpp

@@ -645,7 +645,7 @@ bool AsyncRPCOperation_mergetoaddress::main_impl()
                 wtxHeight = mapBlockIndex[wtx.hashBlock]->nHeight;
                 wtxDepth = wtx.GetDepthInMainChain();
             }
-            LogPrint("zrpcunsafe", "%s: spending note (txid=%s, vjoinsplit=%d, ciphertext=%d, amount=%s, height=%d, confirmations=%d)\n",
+            LogPrint("zrpcunsafe", "%s: spending note (txid=%s, vjoinsplit=%d, jsoutindex=%d, amount=%s, height=%d, confirmations=%d)\n",
                      getId(),
                      jso.hash.ToString().substr(0, 10),
                      jso.js,

src/wallet/asyncrpcoperation_saplingmigration.cpp

@@ -68,6 +68,7 @@ void AsyncRPCOperation_saplingmigration::main() {
 }
 
 bool AsyncRPCOperation_saplingmigration::main_impl() {
+    LogPrint("zrpcunsafe", "%s: Beginning AsyncRPCOperation_saplingmigration.\n", getId());
     std::vector<CSproutNotePlaintextEntry> sproutEntries;
     std::vector<SaplingNoteEntry> saplingEntries;
     {
@@ -83,7 +84,9 @@ bool AsyncRPCOperation_saplingmigration::main_impl() {
     }
     // If the remaining amount to be migrated is less than 0.01 ZEC, end the migration.
     if (availableFunds < CENT) {
-        setMigrationResult(0, 0);
+        LogPrint("zrpcunsafe", "%s: Available Sprout balance (%s) less than required minimum (%s). Stopping.\n",
+            getId(), FormatMoney(availableFunds), FormatMoney(CENT));
+        setMigrationResult(0, 0, std::vector<std::string>());
         return true;
     }
 
@@ -95,12 +98,14 @@ bool AsyncRPCOperation_saplingmigration::main_impl() {
     // Up to the limit of 5, as many transactions are sent as are needed to migrate the remaining funds
     int numTxCreated = 0;
     CAmount amountMigrated = 0;
+    std::vector<std::string> migrationTxIds;
     int noteIndex = 0;
     CCoinsViewCache coinsView(pcoinsTip);
     do {
         CAmount amountToSend = chooseAmount(availableFunds);
         auto builder = TransactionBuilder(consensusParams, targetHeight_, MIGRATION_EXPIRY_DELTA, pwalletMain, pzcashParams,
                                           &coinsView, &cs_main);
+        LogPrint("zrpcunsafe", "%s: Beginning creating transaction with Sapling output amount=%s\n", getId(), FormatMoney(amountToSend - FEE));
         std::vector<CSproutNotePlaintextEntry> fromNotes;
         CAmount fromNoteAmount = 0;
         while (fromNoteAmount < amountToSend) {
@@ -110,6 +115,15 @@ bool AsyncRPCOperation_saplingmigration::main_impl() {
         }
         availableFunds -= fromNoteAmount;
         for (const CSproutNotePlaintextEntry& sproutEntry : fromNotes) {
+            std::string data(sproutEntry.plaintext.memo().begin(), sproutEntry.plaintext.memo().end());
+            LogPrint("zrpcunsafe", "%s: Adding Sprout note input (txid=%s, vjoinsplit=%d, jsoutindex=%d, amount=%s, memo=%s)\n",
+                getId(),
+                sproutEntry.jsop.hash.ToString().substr(0, 10),
+                sproutEntry.jsop.js,
+                int(sproutEntry.jsop.n),  // uint8_t
+                FormatMoney(sproutEntry.plaintext.value()),
+                HexStr(data).substr(0, 10)
+                );
             libzcash::SproutNote sproutNote = sproutEntry.plaintext.note(sproutEntry.address);
             libzcash::SproutSpendingKey sproutSk;
             pwalletMain->GetSproutSpendingKey(sproutEntry.address, sproutSk);
@@ -128,21 +142,30 @@ bool AsyncRPCOperation_saplingmigration::main_impl() {
         builder.AddSaplingOutput(ovkForShieldingFromTaddr(seed), migrationDestAddress, amountToSend - FEE);
         CTransaction tx = builder.Build().GetTxOrThrow();
         if (isCancelled()) {
+            LogPrint("zrpcunsafe", "%s: Canceled. Stopping.\n", getId());
             break;
         }
         pwalletMain->AddPendingSaplingMigrationTx(tx);
+        LogPrint("zrpcunsafe", "%s: Added pending migration transaction with txid=%s\n", getId(), tx.GetHash().ToString());
         ++numTxCreated;
-        amountMigrated += amountToSend;
+        amountMigrated += amountToSend - FEE;
+        migrationTxIds.push_back(tx.GetHash().ToString());
     } while (numTxCreated < 5 && availableFunds > CENT);
 
-    setMigrationResult(numTxCreated, amountMigrated);
+    LogPrint("zrpcunsafe", "%s: Created %d transactions with total Sapling output amount=%s\n", getId(), numTxCreated, FormatMoney(amountMigrated));
+    setMigrationResult(numTxCreated, amountMigrated, migrationTxIds);
     return true;
 }
 
-void AsyncRPCOperation_saplingmigration::setMigrationResult(int numTxCreated, CAmount amountMigrated) {
+void AsyncRPCOperation_saplingmigration::setMigrationResult(int numTxCreated, const CAmount& amountMigrated, const std::vector<std::string>& migrationTxIds) {
     UniValue res(UniValue::VOBJ);
     res.push_back(Pair("num_tx_created", numTxCreated));
     res.push_back(Pair("amount_migrated", FormatMoney(amountMigrated)));
+    UniValue txIds(UniValue::VARR);
+    for (const std::string& txId : migrationTxIds) {
+        txIds.push_back(txId);
+    }
+    res.push_back(Pair("migration_txids", txIds));
     set_result(res);
 }
 

src/wallet/asyncrpcoperation_saplingmigration.h

@@ -29,7 +29,7 @@ private:
 
     bool main_impl();
 
-    void setMigrationResult(int numTxCreated, CAmount amountMigrated);
+    void setMigrationResult(int numTxCreated, const CAmount& amountMigrated, const std::vector<std::string>& migrationTxIds);
 
     CAmount chooseAmount(const CAmount& availableFunds);
 };

src/wallet/asyncrpcoperation_sendmany.cpp

@@ -784,7 +784,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
                 wtxHeight = mapBlockIndex[wtx.hashBlock]->nHeight;
                 wtxDepth = wtx.GetDepthInMainChain();
             }
-            LogPrint("zrpcunsafe", "%s: spending note (txid=%s, vjoinsplit=%d, ciphertext=%d, amount=%s, height=%d, confirmations=%d)\n",
+            LogPrint("zrpcunsafe", "%s: spending note (txid=%s, vjoinsplit=%d, jsoutindex=%d, amount=%s, height=%d, confirmations=%d)\n",
                     getId(),
                     jso.hash.ToString().substr(0, 10),
                     jso.js,
@@ -1048,7 +1048,7 @@ bool AsyncRPCOperation_sendmany::find_unspent_notes() {
     for (CSproutNotePlaintextEntry & entry : sproutEntries) {
         z_sprout_inputs_.push_back(SendManyInputJSOP(entry.jsop, entry.plaintext.note(boost::get<libzcash::SproutPaymentAddress>(frompaymentaddress_)), CAmount(entry.plaintext.value())));
         std::string data(entry.plaintext.memo().begin(), entry.plaintext.memo().end());
-        LogPrint("zrpcunsafe", "%s: found unspent Sprout note (txid=%s, vjoinsplit=%d, ciphertext=%d, amount=%s, memo=%s)\n",
+        LogPrint("zrpcunsafe", "%s: found unspent Sprout note (txid=%s, vjoinsplit=%d, jsoutindex=%d, amount=%s, memo=%s)\n",
             getId(),
             entry.jsop.hash.ToString().substr(0, 10),
             entry.jsop.js,

src/wallet/wallet.cpp

@@ -610,7 +610,7 @@ void CWallet::RunSaplingMigration(int blockHeight) {
     // height N-5
     if (blockHeight % 500 == 495) {
         std::shared_ptr<AsyncRPCQueue> q = getAsyncRPCQueue();
-        std::shared_ptr<AsyncRPCOperation> lastOperation = q->popOperationForId(saplingMigrationOperationId);
+        std::shared_ptr<AsyncRPCOperation> lastOperation = q->getOperationForId(saplingMigrationOperationId);
         if (lastOperation != nullptr) {
             lastOperation->cancel();
         }
@@ -620,7 +620,7 @@ void CWallet::RunSaplingMigration(int blockHeight) {
         q->addOperation(operation);
     } else if (blockHeight % 500 == 499) {
         std::shared_ptr<AsyncRPCQueue> q = getAsyncRPCQueue();
-        std::shared_ptr<AsyncRPCOperation> lastOperation = q->popOperationForId(saplingMigrationOperationId);
+        std::shared_ptr<AsyncRPCOperation> lastOperation = q->getOperationForId(saplingMigrationOperationId);
         if (lastOperation != nullptr) {
             lastOperation->cancel();
         }