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

Closes #2057 by adding extra zrpcunsafe logging #2058

Merged
merged 4 commits into from Feb 2, 2017
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
18 changes: 16 additions & 2 deletions qa/rpc-tests/wallet_protectcoinbase.py
Expand Up @@ -16,7 +16,7 @@ def setup_chain(self):

# Start nodes with -regtestprotectcoinbase to set fCoinbaseMustBeProtected to true.
def setup_network(self, split=False):
self.nodes = start_nodes(3, self.options.tmpdir, extra_args=[['-regtestprotectcoinbase']] * 3 )
self.nodes = start_nodes(3, self.options.tmpdir, extra_args=[['-regtestprotectcoinbase', '-debug=zrpcunsafe']] * 3 )
connect_nodes_bi(self.nodes,0,1)
connect_nodes_bi(self.nodes,1,2)
connect_nodes_bi(self.nodes,0,2)
Expand Down Expand Up @@ -114,11 +114,25 @@ def run_test (self):
recipients = []
recipients.append({"address":myzaddr, "amount": Decimal('20.0') - Decimal('0.0001')})
myopid = self.nodes[0].z_sendmany(mytaddr, recipients)
self.wait_and_assert_operationid_status(myopid)
mytxid = self.wait_and_assert_operationid_status(myopid)
self.sync_all()
self.nodes[1].generate(1)
self.sync_all()

# Verify that debug=zrpcunsafe logs params, and that full txid is associated with opid
logpath = self.options.tmpdir+"/node0/regtest/debug.log"
logcounter = 0
with open(logpath, "r") as myfile:
logdata = myfile.readlines()
for logline in logdata:
if myopid + ": z_sendmany initialized" in logline and mytaddr in logline and myzaddr in logline:
assert_equal(logcounter, 0) # verify order of log messages
logcounter = logcounter + 1
if myopid + ": z_sendmany finished" in logline and mytxid in logline:
assert_equal(logcounter, 1)
logcounter = logcounter + 1
assert_equal(logcounter, 2)

# check balances (the z_sendmany consumes 3 coinbase utxos)
resp = self.nodes[0].z_gettotalbalance()
assert_equal(Decimal(resp["transparent"]), Decimal('20.0'))
Expand Down
43 changes: 25 additions & 18 deletions src/wallet/asyncrpcoperation_sendmany.cpp
Expand Up @@ -91,6 +91,13 @@ AsyncRPCOperation_sendmany::AsyncRPCOperation_sendmany(
throw JSONRPCError(RPC_INVALID_ADDRESS_OR_KEY, string("runtime error: ") + e.what());
}
}

// Log the context info i.e. the call parameters to z_sendmany
if (LogAcceptCategory("zrpcunsafe")) {
LogPrint("zrpcunsafe", "%s: z_sendmany initialized (params=%s)\n", getId(), json_spirit::write_string( contextInfo, false));
} else {
LogPrint("zrpc", "%s: z_sendmany initialized\n", getId());
}
}

AsyncRPCOperation_sendmany::~AsyncRPCOperation_sendmany() {
Expand Down Expand Up @@ -134,9 +141,9 @@ void AsyncRPCOperation_sendmany::main() {
set_state(OperationStatus::FAILED);
}

std::string s = strprintf("async rpc %s finished (status=%s", getId(), getStateAsString());
std::string s = strprintf("%s: z_sendmany finished (status=%s", getId(), getStateAsString());
if (success) {
s += strprintf(", tx=%s)\n", tx_.ToString());
s += strprintf(", txid=%s)\n", tx_.GetHash().ToString());
} else {
s += strprintf(", error=%s)\n", getErrorMessage());
}
Expand Down Expand Up @@ -270,12 +277,12 @@ bool AsyncRPCOperation_sendmany::main_impl() {
}

LogPrint("zrpc", "%s: spending %s to send %s with fee %s\n",
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Non-blocking: I think this might need to be zrpcunsafe, depending on the source/destination (based on my understanding that zrpcunsafe is for anything that logs data which would otherwise be encrypted on the block chain).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Filed a PR where we can discuss and modify for 1.0.6 release: #2060

getId().substr(0,10), FormatMoney(targetAmount, false), FormatMoney(sendAmount, false), FormatMoney(minersFee, false));
LogPrint("zrpc", " - transparent input: %s (to choose from)\n", FormatMoney(t_inputs_total, false));
LogPrint("zrpc", " - private input: %s (to choose from)\n", FormatMoney(z_inputs_total, false));
LogPrint("zrpc", " - transparent output: %s\n", FormatMoney(t_outputs_total, false));
LogPrint("zrpc", " - private output: %s\n", FormatMoney(z_outputs_total, false));
LogPrint("zrpc", " - fee: %s\n", FormatMoney(minersFee, false));
getId(), FormatMoney(targetAmount, false), FormatMoney(sendAmount, false), FormatMoney(minersFee, false));
LogPrint("zrpc", "%s: - transparent input: %s (to choose from)\n", getId(), FormatMoney(t_inputs_total, false));
LogPrint("zrpc", "%s: - private input: %s (to choose from)\n", getId(), FormatMoney(z_inputs_total, false));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Non-blocking: I think this should be zrpcunsafe.

LogPrint("zrpc", "%s: - transparent output: %s\n", getId(), FormatMoney(t_outputs_total, false));
LogPrint("zrpc", "%s: - private output: %s\n", getId(), FormatMoney(z_outputs_total, false));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Non-blocking: I think this should be zrpcunsafe.

LogPrint("zrpc", "%s: - fee: %s\n", getId(), FormatMoney(minersFee, false));

/**
* SCENARIO #1
Expand All @@ -295,7 +302,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
add_taddr_change_output_to_tx(change);

LogPrint("zrpc", "%s: transparent change in transaction output (amount=%s)\n",
getId().substr(0, 10),
getId(),
FormatMoney(change, false)
);
}
Expand Down Expand Up @@ -371,7 +378,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
} else {
add_taddr_change_output_to_tx(change);
LogPrint("zrpc", "%s: transparent change in transaction output (amount=%s)\n",
getId().substr(0, 10),
getId(),
FormatMoney(change, false)
);
}
Expand Down Expand Up @@ -461,7 +468,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
wtxDepth = wtx.GetDepthInMainChain();
}
LogPrint("zrpc", "%s: spending note (txid=%s, vjoinsplit=%d, ciphertext=%d, amount=%s, height=%d, confirmations=%d)\n",
getId().substr(0, 10),
getId(),
outPoint.hash.ToString().substr(0, 10),
outPoint.js,
int(outPoint.n), // uint8_t
Expand Down Expand Up @@ -490,7 +497,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
info.vjsout.push_back(JSOutput(frompaymentaddress_, jsChange));

LogPrint("zrpc", "%s: generating note for change (amount=%s)\n",
getId().substr(0, 10),
getId(),
FormatMoney(jsChange, false)
);
}
Expand Down Expand Up @@ -586,7 +593,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
jsInputValue += plaintext.value;

LogPrint("zrpc", "%s: spending change (amount=%s)\n",
getId().substr(0, 10),
getId(),
FormatMoney(plaintext.value, false)
);

Expand Down Expand Up @@ -633,7 +640,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
wtxDepth = wtx.GetDepthInMainChain();
}
LogPrint("zrpc", "%s: spending note (txid=%s, vjoinsplit=%d, ciphertext=%d, amount=%s, height=%d, confirmations=%d)\n",
getId().substr(0, 10),
getId(),
jso.hash.ToString().substr(0, 10),
jso.js,
int(jso.n), // uint8_t
Expand Down Expand Up @@ -728,7 +735,7 @@ bool AsyncRPCOperation_sendmany::main_impl() {
info.vjsout.push_back(JSOutput(frompaymentaddress_, jsChange));

LogPrint("zrpc", "%s: generating note for change (amount=%s)\n",
getId().substr(0, 10),
getId(),
FormatMoney(jsChange, false)
);
}
Expand Down Expand Up @@ -864,7 +871,7 @@ bool AsyncRPCOperation_sendmany::find_unspent_notes() {
std::string data(entry.plaintext.memo.begin(), entry.plaintext.memo.end());
if (LogAcceptCategory("zrpcunsafe")) {
LogPrint("zrpcunsafe", "%s: found unspent note (txid=%s, vjoinsplit=%d, ciphertext=%d, amount=%s, memo=%s)\n",
getId().substr(0, 10),
getId(),
entry.jsop.hash.ToString().substr(0, 10),
entry.jsop.js,
int(entry.jsop.n), // uint8_t
Expand All @@ -873,7 +880,7 @@ bool AsyncRPCOperation_sendmany::find_unspent_notes() {
);
} else {
LogPrint("zrpc", "%s: found unspent note (txid=%s, vjoinsplit=%d, ciphertext=%d, amount=%s)\n",
getId().substr(0, 10),
getId(),
entry.jsop.hash.ToString().substr(0, 10),
entry.jsop.js,
int(entry.jsop.n), // uint8_t
Expand Down Expand Up @@ -951,7 +958,7 @@ Object AsyncRPCOperation_sendmany::perform_joinsplit(
CMutableTransaction mtx(tx_);

LogPrint("zrpc", "%s: creating joinsplit at index %d (vpub_old=%s, vpub_new=%s, in[0]=%s, in[1]=%s, out[0]=%s, out[1]=%s)\n",
getId().substr(0,10),
getId(),
tx_.vjoinsplit.size(),
FormatMoney(info.vpub_old, false), FormatMoney(info.vpub_new, false),
FormatMoney(info.vjsin[0].note.value, false), FormatMoney(info.vjsin[1].note.value, false),
Expand Down