#16115 On bitcoind startup, write config args to debug.log (config)

https://github.com/bitcoin/bitcoin/16115

Host: jnewbery

Notes

  • Configuration options can either be specified in a config file or passed as command-line arguments to the bitcoind or bitcoin-qt executable.
  • Config file and command line configuration interact in complex ways. See PR 15934 for a full treatment of how configuration options are merged and parsed.
  • The configuration options affect node behaviour at runtime in various ways.
  • When debugging or troubleshooting node issues, it’s very useful to know what configuration was applied to the node, but that information is not always available.
  • This PR prints the config file and command line configuration to the debug.log file on startup.
  • The PR was later updated to also reprint configuration options when the log file rotates.

Questions

  • In a review comment, Carl Dong suggests that it’d be “very useful to have the effective command line configuration at-a-glance”. How does this differ from what has been implemented in this PR? Why would it be difficult to implement?
  • Reviewers asked the PR author to add a blacklist of configuration that shouldn’t be logged. The author implemented that here. What are your thoughts about that implementation of a blacklist?
  • What is Bitcoin Core log shrinking? Where is it implemented?
  • What is log rotation? How can it be used for Bitcoin Core logs?
  • What is the purpose of the second commit in this PR (re-log configuration when debug.log is reopened)? What are your thoughts about that additional functionality?
  • What tests are included in this PR? Could any additional tests be added?

Meeting Log

13:00 < jnewbery> hi
13:00 < nehan> hi
13:00 < jkczyz> hi
13:00 < lightlike> hello
13:00 < ariard> hi
13:00 < jnewbery> today's notes/questions are at: https://bitcoin-core-review-club.github.io/16115.html
13:01 < jonatack> hi
13:01 < jnewbery> jkczyz: I see you already left review comments. Great!
13:01 < jnewbery> What were your overall thoughts on the PR?
13:02 < jnewbery> (open to anyone)
13:02 < digi_james> Hello
13:02 < jkczyz> Undecided if this is preferable to a command to print the args
13:03 < jnewbery> I think there's a PR that does that (RPC to print args) too
13:04 < jonatack> seems somewhat brittle, unfinished, and needs more test coverage
13:04 < jonatack> though good idea
13:04 < fjahr> Yeah, #15493 is the PR for print args
13:04 < jnewbery> jonatack: what part do you think is brittle
13:05 < jonatack> the blacklist part
13:05 < kanzure> hi
13:05 < jnewbery> fjahr: I don't think that's an RPC. That's a command line arg to pass to bitcoind
13:05 < michaelfolkson> I wasn't sure on the Concept ACK
13:05 < jnewbery> maybe 15493 was the one I was thinking of
13:06 < lightlike> certainly like the concept of writing the down this info. not sure if the second commit around rotating logs is needed (liked jkczyz comment about this).
13:06 < jnewbery> jkczyz: can you think of any advantage to logging to debug.log instead of an RPC?
13:06 < jonatack> jtczyz: yes, nice job on the review
13:07 < fjahr> jnewbery: that's the same number?
13:07 < jkczyz> jnewbery: Yeah, in cases where there is a crash under the given configuration
13:07 < jnewbery> fjahr: yes, I think I misremembered what that PR was doing
13:07 < fjahr> ah, got it
13:08 < jnewbery> jkczyz: right. Sometimes debug.log is all we've got. A user says "something strange happened" and we don't know what the config was
13:09 < michaelfolkson> But are we expecting them to give the whole debug.log from beginning to end? The config will be right at the start
13:09 < jnewbery> lighlike: yeah, I agree with your point about the second commit. It doesn't need to be bundled into the same PR
13:09 < michaelfolkson> Surely better to provide them separately
13:10 < jnewbery> michaelfolkson: (re: are we expecting them...) perhaps, but better to log somewhere than nowhere
13:10 < jnewbery> first question: in a review comment, Carl Dong suggests that it’d be “very useful to have the effective command line configuration at-a-glance”. How does this differ from what has been implemented in this PR? Why would it be difficult to implement?
13:11 < michaelfolkson> Provide two different logs? You only need the recent output to see what the problem was in the debug log
13:11 < nehan> i assumed he meant the values for all commandline arguments instead of just user-passed in ones
13:12 < jnewbery> nehan: that's part of it
13:12 < nehan> as promag points out that seems difficult because initialization happens all over the place
13:12 < jnewbery> all commandline args have default values. This PR doesn't print what those default values are if nothing is passed in explicitly
13:13 < jnewbery> there are also commandline args that interact with each other, so if one is set then it affects others
13:13 < jnewbery> eg https://github.com/bitcoin/bitcoin/blob/a7aa809027633556dd3280c6e29ca98eb3235a3d/src/init.cpp#L765
13:14 < jnewbery> nehan: yes, it's difficult because gArgs is accessed all over the code, and the actual values are only read/calculated where they're needed
13:14 < jnewbery> Next question: Reviewers asked the PR author to add a blacklist of configuration that shouldn’t be logged. The author implemented that here. What are your thoughts about that implementation of a blacklist?
13:15 < jnewbery> (here: https://github.com/bitcoin/bitcoin/pull/16115/files#diff-c9721a8bab21576f98fa79fda2715408R967)
13:15 < nehan> it would be easy for someone adding a sensitive argument to forget to update that blacklist
13:16 < jnewbery> nehan: I agree!
13:16 < nehan> i didn't look to see if there is a place in the code anyone adding an argument must update.  if so, it would be good to add a comment there referencing the blacklist.
13:16 < jnewbery> any suggestions on a different implementation?
13:17 < jnewbery> nehan: good idea
13:17 < jonatack> a whitelist would be safer, though probably more involved
13:17 < jkczyz> Perhaps it could be built into the arg code. A bit saying if it should be blacklisted
13:17 < probably_dillon> a whitelist would suffer from the same "and what if someone forgets it?" problem
13:17 < fjahr> there should be a explicit declaration on each argument
13:17 < jnewbery> jonatack: yes. It suffers from the same problem (people forgetting to update it), but the impact is probably less bad
13:18 < jonatack> yes, not the same probable consequences
13:18 < fjahr> not when calling it, I mean as a type of something like taht in the code
13:18 < jnewbery> jkczyz,fjahr: yeah, perhaps a new 'sensitive data' flag could be added here: https://github.com/bitcoin/bitcoin/blob/a7aa809027633556dd3280c6e29ca98eb3235a3d/src/util/system.cpp#L542
13:19 < jnewbery> here's one existing flag: https://github.com/bitcoin/bitcoin/blob/a7aa809027633556dd3280c6e29ca98eb3235a3d/src/util/system.h#L138
13:20 < jnewbery> next question: What is Bitcoin Core log shrinking? Where is it implemented?
13:20 < nehan> ShrinkDebugFile() in logging.cpp
13:20 < jkczyz> Truncates start of log file if it grows too large (over 10MB * 110% = 11MB)
13:21 < michaelfolkson> Only on startup
13:21 < lightlike> called in init at startup (before logging anything else)
13:21 < jnewbery> nehan, jkczyz, michaelfolkson, lighlike: great answers :)
13:21 < jnewbery> any questions on what that's doing?
13:22 < michaelfolkson> What was the rationale for only shrinking on startup?
13:22 < jnewbery> If not, let's move on to the next question: What is log rotation? How can it be used for Bitcoin Core logs?
13:23 < michaelfolkson> Addresses problem of not shrinking the log after startup
13:23 < jkczyz> A tool for limiting the size of log files by breaking into multiple files
13:24 < jnewbery> fascinating. ShrinkDebugFile() was added by Satoshi: https://github.com/jnewbery/bitcoin/blob/0bbbee96b742e4ad0fd5e1d3c33e4bd2247e4445/util.cpp#L456
13:24 < jnewbery> jkczyz: right. Did you find where support for log rotation was added to bitcoin core?
13:25 < probably_dillon> is there something wrong with just relying a system's logrotate?
13:25 < jkczyz> jnewbery: I did not. Just assumed people used external tools for it
13:26 < jkczyz> jnewbery: I think I saw a PR where someone wanted to add it, though
13:26 < jnewbery> probably_dillon: that's exactly what happens. bitcoind does not rotate its own log files
13:26 < jnewbery> support for SIGHUP was added here: https://github.com/bitcoin/bitcoin/pull/917
13:26 < jnewbery> the PR author (LarryRuane) gives a good explanation of log rotation here: https://github.com/bitcoin/bitcoin/pull/16115#pullrequestreview-250179580
13:27 < jnewbery> External log rotation tools can be configured to prevent the log file from growing unbounded, see #917. Typically the way these tools work is, they first move (as in, the rename system call) debug.log to a different name....
13:27 < jnewbery> We've already addressed the next question, but any other thoughts about "What is the purpose of the second commit in this PR (re-log configuration when debug.log is reopened)? What are your thoughts about that additional functionality?"
13:28 < nehan> 1) 200 seems arbitrary 2) I think the logrotator should support saving the startup log instead of doing this
13:29 < jnewbery> nehan: I agree with both of those
13:29 < nehan> now someone has to think about whether or not to put information into this special re-log thing
13:30 < lightlike> I wonder if there are many users how use logrotate and delete the old logs immediately, so that writing the options down again is needed.
13:30 < probably_dillon> nehan: do you mean implementing this as a new "boot config log" log?
13:30 < jnewbery> I also didn't like the fact that the log timestamps are no longer monotonic after this PR
13:30 < jnewbery> That's probably going to confuse some log parsers
13:31 < nehan> probably_di: i don't think saving (or reprinting) initial log information should be handled in bitcoind
13:31 < jonatack> nehan: agreed. brittle.
13:32 < jkczyz> If args are logged at startup, it might be useful providing docs on how to configure the logrotate properly
13:33 < jnewbery> jkczyz: I agree that this is better addressed with documentation than adding complexity to the code. I don't know where exactly that documentation should live
13:34 < jnewbery> There is already precedence for including user tips in the /docs directory, eg: https://github.com/bitcoin/bitcoin/blob/master/doc/reduce-memory.md
13:34 < jnewbery> ok, final question: What tests are included in this PR? Could any additional tests be added?
13:35 < jonatack> The PR includes one functional test that launches a node, passing one blacklisted arg and one whitelisted arg, and verifies they are in the debug log with the blacklisted arg as ****.
13:35 < fjahr> a functional test that is called unit test in the commit message
13:35 < jkczyz> could include a test for blacklisted args with '-regtest.' or other such prefixes
13:35 < jonatack> For one, I'd like to see some edge cases tested as well.
13:36 < michaelfolkson> Such as?
13:36 < jonatack> such as jkczyz's suggestion
13:37 < probably_dillon> testing the whole blacklist seems prudent.
13:37 < jonatack> probably
13:37 < jonatack> probably_dillon: yes
13:38 < lightlike> the commit message is wrong ("unit test"), should be functional
13:39 < jnewbery> this also seems like a good candidate for unit tests, since the new functionality is in a single class (ArgsManager)
13:39 < jnewbery> There are already units tests for ArgsManager, eg https://github.com/bitcoin/bitcoin/blob/master/src/test/getarg_tests.cpp
13:39 < jonatack> Unit tests for the code changes would be nice, too, esp the blacklist
13:39 < jnewbery> ok, that's all I had. Did anyone else have any remaining questions/comments they wanted to bring up?
13:40 < lightlike> (sorry, missed comment by fjahr)
13:40 < michaelfolkson> If you were to use a sensitive flag you could run a test to ensure the flag catches all entries
13:40 < michaelfolkson> What are your thoughts on how this PR should progress @jnewbery? Suggest the flag on the PR?
13:41 < jkczyz> michaelfolkson: Was goind to say the same :)
13:41 < michaelfolkson> Or keep it in documentation?
13:41 < jnewbery> michaelfolkson: My main piece of feedback is: split the PR in two. No need to bundle two changes in the same PR
13:41 < michaelfolkson> Or continue improving the PR as designed?
13:41 < jnewbery> I'm a concept ACK on the first commit, but a weak concept NACK on the second
13:42 < nehan> when i ran this, my debug.log had the following: 2019-08-14T15:56:58Z Warning: Unsupported logging category -debug=cmdline1.
13:42 < nehan> i couldn't track down why that was happening.  do you know?
13:43 < jnewbery> the `-debug` argument takes one or more logging categories. cmdline1 is not a valid logging category
13:43 < nehan> ok, thanks. it wasn't in the log mentioned in https://github.com/bitcoin/bitcoin/pull/16115#issue-283090468
13:43 < jnewbery> the log came from here: https://github.com/bitcoin/bitcoin/blob/a7aa809027633556dd3280c6e29ca98eb3235a3d/src/init.cpp#L1005
13:43 < jnewbery> I suspect you'd see the same thing on master
13:44 < jnewbery> any other questions?
13:45 < michaelfolkson> I have a question on the config. As a first time user I agonized over what in the config file I could change later and what I needed to get right before installing. Should this be made clearer?
13:45 < jnewbery> what do you mean 'before installing'?
13:45 < michaelfolkson> Some choices can't be reversed eg testnet choice, once pruned can't unprune
13:46 < michaelfolkson> Other choices can be changed later eg which nodes you connect to
13:46 < michaelfolkson> I don't know how many fit in that first category, probably not many
13:46 < jonatack> michaelfolkson: before IBD?
13:46 < michaelfolkson> Sorry yes
13:46 < jonatack> that seems like a great question
13:47 < jnewbery> Yeah, I'm not sure. I think `bitcoind --help` should probably give you the information you need. If you think the help text is lacking, then you should open a PR to improve it.
13:47 < fjahr> you could do both on the same machine using the same bitcoind, with a different datadir
13:47 < jnewbery> There's also this, that might help you: https://jlopp.github.io/bitcoin-core-config-generator/
13:47 < jnewbery> (repo here: https://github.com/jlopp/bitcoin-core-config-generator)
13:48 < michaelfolkson> Yeah that is helpful. Doesn't address this currently
13:48 < michaelfolkson> That's good suggestion <fjahr>
13:48 < jonatack> maybe an initial node setup doc in the /doc dir
13:48 < wumpus> -prune and -txindex are probably the only options that you want to be sure to get right before ibd because they take quite some time to switch around
13:49 < jnewbery> wumpus: I think -txindex is much better now that it happens in a background thread (it can be switched on and off)
13:49 < wumpus> prune because it throws away blocks, txindex because it's a huge amont of work to build the index
13:49 < michaelfolkson> Cool, thanks. I remember it really slowed me down because I didn't want to make wrong choices that weren't easily reversible
13:50 < jnewbery> I think prune is the important one
13:50 < wumpus> jnewbery: it's definitely become better
13:50 < jnewbery> any final questions, or are people happy to wrap it up there?
13:50 < wumpus> still txindex can take quite a long time too. that it happens in the background doesn't make it faster :)
13:50 < jonatack> michaelfolkson: this state of mind can be precious for adding docs
13:51 < jonatack> initial perspective
13:51 < jnewbery> wumpus: yeah, it's still slow, but at least you don't have to reindex to add it, which I think was the case before
13:51 < michaelfolkson> Yeah should take advantage of it whilst I still have it ;)
13:52 < jnewbery> lots of great questions this week. Thanks everyone (and thanks wumpus for stopping by!)
13:52 < jnewbery> Here's your homework for next week:
13:52 < michaelfolkson> Yeah, was great. Thanks everyone
13:53 < jnewbery> - review https://bitcoin-core-review-club.github.io/15931.html. I'll try to get notes and questions up in the next couple of days
13:53 < jnewbery> - leave comments on this week's PR (https://github.com/bitcoin/bitcoin/pull/16115)
13:53 < jnewbery> - take a look through the open PRs (either https://github.com/bitcoin/bitcoin/pulls or https://bitcoinacks.com/), and see if there are any you think would be interesting for us to discuss
13:54 < jnewbery> I'm still waiting for my first comment in here: https://github.com/bitcoin-core-review-club/bitcoin-core-review-club.github.io/issues/14 :)
13:54 < jnewbery> that's it. Thanks everyone!
13:54 < fjahr> thanks jnewbery
13:54 < wumpus> jnewbery: true, it used to be that even removing the index took a full reindex, at least removing it should be fast now !
13:54 < wumpus> yes thanks everyone
13:55 < lightlike> thanks!
13:55 < michaelfolkson> Ah it is an issue <jnewbery>. I was looking for that a couple of weeks ago haha
13:55 < jkczyz> yeah, good session!
13:55 < jonatack> jnewbery, wumpus: thanks! ... thanks, everyone!
13:55 < fanquake> That PSBT shuffle inputs PR will be a good one.
13:55 < nehan> thanks!