Log RPC parameters (arguments) if -debug=rpcparams #16365

LarryRuane · 2019-07-09T20:58:19Z

When a developer is examining debug.log (or client terminal output), it's often useful to know which RPCs have been submitted to the client; this can be enabled with the -debug=rpc configuration option. But this prints only the method name. This PR adds -debug=rpcparams to enable the logging of each RPC's parameters (arguments). The parameters of certain RPCs are keys or passwords; these should not be logged.

maflcko · 2019-07-09T21:03:14Z

src/rpc/server.cpp

+        "encryptwallet",
+        "walletpassphrase",
+        "walletpassphrasechange",
+    };


Looks like this list is incomplete. Would be nice if it can be deduplicated with the existing QStringList historyFilter

This blacklist should be pulled out of a config rather than buried in the code.

What do you mean by "config"? Are you referring to ~/.bitcoin/bitcoin.conf?

I mean that it should go into a common module, probably ./src/util/ or similar.

DrahtBot · 2019-07-09T22:34:20Z

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#22736 (log, sync: change lock contention from preprocessor directive to log category by jonatack)
#20487 (Add syscall sandboxing using seccomp-bpf (Linux secure computing mode) by practicalswift)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

promag · 2019-07-10T21:48:30Z

How about private keys?

LarryRuane

Rebased, addressed review comments, force-pushed.

LarryRuane · 2019-07-11T05:04:04Z

src/logging.h

@@ -54,6 +54,7 @@ namespace BCLog {
        COINDB      = (1 << 18),
        QT          = (1 << 19),
        LEVELDB     = (1 << 20),
+        RPCPARAMS   = (1 << 21),


I'm undecided if a new category is needed, or just enable this additional logging with rpc. We don't have many of the 32 category bits remaining (although we could easily change to use a uint64_t).

LarryRuane · 2019-07-11T05:05:57Z

src/rpc/request.cpp

+                LogPrint(BCLog::RPCPARAMS, ",");
+            LogPrint(BCLog::RPCPARAMS, "%s", SanitizeString(params[i].getValStr()));
+        }
+        LogPrint(BCLog::RPCPARAMS, "]\n");


Could print each param on a separate line.

promag · 2019-07-12T00:56:02Z

IMO the blacklist doesn't look a great option.

How about disallow -debug=rpcparams in mainnet and drop the blacklist?

instagibbs · 2019-07-12T18:16:06Z

concept NACK, someone is going to forget when adding a new RPC and start logging secrets in production.

I think @promag suggestion is better.

promag · 2019-08-05T14:04:14Z

Another approach is to add a sensitive options/flag (false by default) to ~~RPCHelpMan~~ RPCArg.

LarryRuane · 2019-08-06T06:19:00Z

@promag, interesting idea, I like that it would allow specific arguments to be designated as sensitive, rather than the entire method. Also, it would be nice not to have to touch so many lines of code (as my latest commit does). But @instagibbs's concern, #16365 (comment), which I was attempted to overcome with my latest commit, becomes live again.

LarryRuane · 2019-08-22T18:28:43Z

Rebased, replaced functional (python) test with a proper unit test.

LarryRuane · 2019-09-02T20:35:57Z

I had an idea for what may be an improvement. It's in a separate commit, "replace sensitive bool with more general flags". Please let me know what you think; this commit is optional.

Modifying all of the lines of the static const CRPCCommand commands[] tables is disruptive, and all that's being done is to add a boolean value (to indicate whether to log the RPC's params or not). As long as we're touching all these lines anyway, why not implement a more general flags bitfield, of which DONTLOG is just the first bit. There may be other future attributes that would be useful to add to RPC methods. With this commit, adding them would touch only the lines corresponding to the affected RPCs, rather than all of them.

LarryRuane · 2020-09-29T06:05:12Z

Force-pushed (diff) a different approach that does not require changing each of the 149 per-rpc CRPCCommand initializers. This new way is much less invasive and more manageable. I finally decided it's best to go with an "allow" list (hard to beat simplicity). If someone adds a new RPC later without being aware of this form of logging, its arguments will not be logged. That makes this approach very safe against accidentally leaking secret information to the log file. I incorporated some of the review comments as well.

Here are some examples (without showing the RPC output):

$ bitcoin-cli getnetworkinfo
$ bitcoin-cli getblockhash 0
$ bitcoin-cli logging '["rpcparams"]' '["rpc","mempool"]'
$ bitcoin-cli encryptwallet WALLET-PASSWORD-SECRET

Here's what appears in debug.log:

2020-09-29T05:58:50Z rpc=getnetworkinfo()
2020-09-29T05:59:00Z rpc=getblockhash(0)
2020-09-29T06:02:51Z rpc=logging([rpcparams],[rpc,mempool])
2020-09-29T06:02:55Z rpc=encryptwallet(****)

LarryRuane · 2020-09-29T14:58:36Z

src/rpc/server.cpp

+            "walletcreatefundedpsbt",
+            "walletlock",
+            "walletprocesspsbt",
+        };


This allow list came from listing all the RPCs and then removing the following:

signmessagewithprivkey signrawtransactionwithkey signrawtransactionwithwallet signmessage createwallet encryptwallet importmulti importprivkey sethdseed walletpassphrase walletpassphrasechange

As far as I can tell, these are the RPCs whose arguments shouldn't be logged.

Maintainence of this list seems like a drawback. It would be nice if a test fails somewhere when an RPC is added or removed without the allow list being updated, e.g. with a list of structs of all the RPCs with an associated safe/unsafe bool value, or something like CRPCConvertParam. Feel to ignore if unrealistic.

jonatack

Tested almost-ACK 7d22a6f rebased to current master, modulo the comments below

jonatack · 2021-08-19T11:02:57Z

src/logging.h

@@ -59,6 +59,7 @@ namespace BCLog {
        VALIDATION  = (1 << 21),
        I2P         = (1 << 22),
        IPC         = (1 << 23),
+        RPCPARAMS   = (1 << 24),


test/functional/rpc_misc.py::L60 needs to be updated: AssertionError: not(25 == 24)

jonatack · 2021-08-19T11:04:18Z

src/rpc/server.cpp

+            "psbtbumpfee",
+            "reconsiderblock",
+            "removeprunedfunds",
+            "rescanblockchain",


This list seems to need an update for new RPCS (restorewallet comes to mind, not sure if there are others)

jonatack · 2021-08-19T11:10:46Z

src/rpc/server.cpp

+            "walletcreatefundedpsbt",
+            "walletlock",
+            "walletprocesspsbt",
+        };


Maintainence of this list seems like a drawback. It would be nice if a test fails somewhere when an RPC is added or removed without the allow list being updated, e.g. with a list of structs of all the RPCs with an associated safe/unsafe bool value, or something like CRPCConvertParam. Feel to ignore if unrealistic.

jonatack · 2021-08-19T11:11:15Z

src/rpc/server.cpp

+                    params += ",";
+                }
+                params += request.params[i].write();
+            }


Maybe replace this loop with a call to util/string.h::Join()

jonatack · 2021-08-19T11:37:51Z

src/test/rpc_tests.cpp

+    BOOST_CHECK(str.find("rpc=signmessagewithprivkey(****)") != std::string::npos);
+    // Make sure these don't somehow appear
+    BOOST_CHECK(str.find("some-key") == std::string::npos);
+    BOOST_CHECK(str.find("some-message") == std::string::npos);


Some (tested) ideas, feel free to pick/choose/ignore

- FILE* file = fsbridge::fopen(LogInstance().m_file_path, "rb"); + FILE* file{fsbridge::fopen(LogInstance().m_file_path, "rb")}; fseek(file, 0, SEEK_END); std::vector<char> vch(ftell(file), 0); fseek(file, 0, SEEK_SET); - size_t nbytes = fread(vch.data(), 1, vch.size(), file); + const size_t nbytes{fread(vch.data(), 1, vch.size(), file)}; fclose(file); // This checks the test (not the code being tested). BOOST_CHECK_EQUAL(nbytes, vch.size()); // Check that what should appear does, and what shouldn't doesn't. - std::string str(vch.begin(), vch.end()); + const std::string str{vch.begin(), vch.end()}; @@ -512,8 +512,8 @@ BOOST_AUTO_TEST_CASE(rpc_logparams) - BOOST_CHECK(str.find("some-key") == std::string::npos); - BOOST_CHECK(str.find("some-message") == std::string::npos); + BOOST_CHECK_EQUAL(str.find("some-key"), std::string::npos); + BOOST_CHECK_EQUAL(str.find("some-message"), std::string::npos);

jonatack · 2021-08-19T11:49:04Z

src/rpc/server.cpp

+        } else {
+            for (size_t i = 0; i < request.params.size(); ++i) {
+                if (i > 0) {
+                    params += ",";


Not sure here, perhaps separate the params with ", " (comma + space)

now

2021-08-19T11:45:46Z rpc=getmempoolancestors(b6a5ed05bc71c8ccc5316,true)

comma+space

2021-08-19T11:45:46Z rpc=getmempoolancestors(b6a5ed05bc71c8ccc5316, true)

LarryRuane · 2021-08-20T15:37:19Z

Maintenance of this list seems like a drawback

I agree, I'm going to convert this PR to draft because I think there's a better way to do this that doesn't require a separate list. I'll also pick up your other suggestions. Thanks for taking the time to look it over!

DrahtBot · 2021-12-13T23:19:50Z

🐙 This pull request conflicts with the target branch and needs rebase.

_{Want to unsubscribe from rebase notifications on this pull request? Just convert this pull request to a "draft".}

DrahtBot · 2022-03-21T13:07:48Z

There hasn't been much activity lately and the patch still needs rebase. What is the status here?

Is it still relevant? ➡️ Please solve the conflicts to make it ready for review and to ensure the CI passes.
Is it no longer relevant? ➡️ Please close.
Did the author lose interest or time to work on this? ➡️ Please close it and mark it 'Up for grabs' with the label, so that it can be picked up in the future.

fanquake · 2022-12-06T10:45:03Z

I'm going to convert this PR to draft because I think there's a better way to do this that doesn't require a separate list. I'll also pick up your other suggestions.

Given it's been 16 months this statement, I'm going to close this for now. Feel free to comment / ping if you're going to work on this again and need the PR reopened.

maflcko reviewed Jul 9, 2019

View reviewed changes

DrahtBot added the Needs rebase label Jul 9, 2019

fanquake added RPC/REST/ZMQ Utils/log/libs labels Jul 10, 2019

LarryRuane force-pushed the log-rpc-args branch from c5994ff to 91ee96b Compare July 11, 2019 04:54

LarryRuane commented Jul 11, 2019

View reviewed changes

DrahtBot removed the Needs rebase label Jul 11, 2019

LarryRuane force-pushed the log-rpc-args branch 2 times, most recently from 6ab0383 to e484051 Compare July 13, 2019 15:15

DrahtBot added the Needs rebase label Aug 5, 2019

LarryRuane force-pushed the log-rpc-args branch from e484051 to d7f1d81 Compare August 6, 2019 06:10

DrahtBot removed the Needs rebase label Aug 6, 2019

DrahtBot added the Needs rebase label Aug 21, 2019

LarryRuane force-pushed the log-rpc-args branch from d7f1d81 to c0b6bd8 Compare August 22, 2019 18:26

DrahtBot removed the Needs rebase label Aug 22, 2019

DrahtBot added the Needs rebase label Sep 2, 2019

LarryRuane force-pushed the log-rpc-args branch from c0b6bd8 to c3d0a32 Compare September 2, 2019 17:28

DrahtBot removed the Needs rebase label Sep 2, 2019

LarryRuane force-pushed the log-rpc-args branch from c3d0a32 to 2981185 Compare September 2, 2019 19:11

DrahtBot added the Needs rebase label Sep 5, 2019

LarryRuane force-pushed the log-rpc-args branch from b397f7e to 9759e70 Compare September 5, 2019 14:10

DrahtBot removed the Needs rebase label Sep 5, 2019

LarryRuane force-pushed the log-rpc-args branch from 9edf0ca to 45fb5d0 Compare September 29, 2020 05:48

LarryRuane changed the title ~~[WIP] Log RPC parameters (arguments) if -debug=rpcparams~~ Log RPC parameters (arguments) if -debug=rpcparams Sep 29, 2020

LarryRuane commented Sep 29, 2020

View reviewed changes

DrahtBot mentioned this pull request Nov 25, 2020

Add syscall sandboxing using seccomp-bpf (Linux secure computing mode) #20487

Merged

DrahtBot mentioned this pull request Dec 17, 2020

Add I2P support using I2P SAM #20685

Merged

DrahtBot mentioned this pull request Feb 1, 2021

log: Move "Pre-allocating up to position 0x[…] in […].dat" log message to debug category #21041

Merged

DrahtBot added the Needs rebase label Mar 2, 2021

LarryRuane force-pushed the log-rpc-args branch from 45fb5d0 to 871ec54 Compare March 3, 2021 21:11

DrahtBot removed the Needs rebase label Mar 3, 2021

DrahtBot mentioned this pull request Mar 4, 2021

wallet: createwallet examples for descriptor wallets #21302

Merged

DrahtBot mentioned this pull request Mar 28, 2021

fuzz: Add fuzzing syscall sandbox: detect use of unexpected syscalls when fuzzing ("syscall sanitizer") #21538

Closed

DrahtBot added the Needs rebase label Apr 5, 2021

LarryRuane force-pushed the log-rpc-args branch from 871ec54 to aa72aa0 Compare April 12, 2021 17:49

DrahtBot removed the Needs rebase label Apr 12, 2021

DrahtBot added the Needs rebase label Apr 27, 2021

Log RPC parameters if -debug=rpcparams

7d22a6f

LarryRuane force-pushed the log-rpc-args branch from aa72aa0 to 7d22a6f Compare April 29, 2021 20:02

DrahtBot removed the Needs rebase label Apr 29, 2021

DrahtBot mentioned this pull request Aug 19, 2021

log, sync: change lock contention from preprocessor directive to log category #22736

Merged

jonatack reviewed Aug 19, 2021

View reviewed changes

LarryRuane marked this pull request as draft August 20, 2021 15:37

DrahtBot added the Needs rebase label Dec 13, 2021

fanquake closed this Dec 6, 2022

LarryRuane mentioned this pull request Feb 24, 2023

log RPC arguments for testnets LarryRuane/bitcoin#2

Open

bitcoin locked and limited conversation to collaborators Dec 6, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Log RPC parameters (arguments) if -debug=rpcparams #16365

Log RPC parameters (arguments) if -debug=rpcparams #16365

LarryRuane commented Jul 9, 2019 •

edited

Loading

maflcko Jul 9, 2019

fqlx Jul 10, 2019

LarryRuane Jul 10, 2019

maflcko Jul 10, 2019

DrahtBot commented Jul 9, 2019 •

edited

Loading

promag commented Jul 10, 2019

LarryRuane left a comment

LarryRuane Jul 11, 2019

LarryRuane Jul 11, 2019

promag commented Jul 12, 2019

instagibbs commented Jul 12, 2019

promag commented Aug 5, 2019 •

edited

Loading

LarryRuane commented Aug 6, 2019

LarryRuane commented Aug 22, 2019

LarryRuane commented Sep 2, 2019

LarryRuane commented Sep 29, 2020

LarryRuane Sep 29, 2020

jonatack Aug 19, 2021

jonatack left a comment

jonatack Aug 19, 2021

jonatack Aug 19, 2021

jonatack Aug 19, 2021

jonatack Aug 19, 2021

jonatack Aug 19, 2021

jonatack Aug 19, 2021

LarryRuane commented Aug 20, 2021

DrahtBot commented Dec 13, 2021

DrahtBot commented Mar 21, 2022

fanquake commented Dec 6, 2022

Log RPC parameters (arguments) if -debug=rpcparams #16365

Log RPC parameters (arguments) if -debug=rpcparams #16365

Conversation

LarryRuane commented Jul 9, 2019 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

DrahtBot commented Jul 9, 2019 • edited Loading

Conflicts

promag commented Jul 10, 2019

LarryRuane left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

promag commented Jul 12, 2019

instagibbs commented Jul 12, 2019

promag commented Aug 5, 2019 • edited Loading

LarryRuane commented Aug 6, 2019

LarryRuane commented Aug 22, 2019

LarryRuane commented Sep 2, 2019

LarryRuane commented Sep 29, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jonatack left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

LarryRuane commented Aug 20, 2021

DrahtBot commented Dec 13, 2021

DrahtBot commented Mar 21, 2022

fanquake commented Dec 6, 2022

LarryRuane commented Jul 9, 2019 •

edited

Loading

DrahtBot commented Jul 9, 2019 •

edited

Loading

promag commented Aug 5, 2019 •

edited

Loading