libs)

Aug 14, 2019

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

Host: jnewbery - PR author: LarryRuane

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

100

13:37

<probably_dillon> testing the whole blacklist seems prudent.

101

13:37

<jonatack> probably

102

13:37

<jonatack> probably_dillon: yes

103

13:38

<lightlike> the commit message is wrong ("unit test"), should be functional

104

13:39

<jnewbery> this also seems like a good candidate for unit tests, since the new functionality is in a single class (ArgsManager)

105

13:39

<jnewbery> There are already units tests for ArgsManager, eg https://github.com/bitcoin/bitcoin/blob/master/src/test/getarg_tests.cpp

106

13:39

<jonatack> Unit tests for the code changes would be nice, too, esp the blacklist

107

13:39

<jnewbery> ok, that's all I had. Did anyone else have any remaining questions/comments they wanted to bring up?

108

13:40

<lightlike> (sorry, missed comment by fjahr)

109

13:40

<michaelfolkson> If you were to use a sensitive flag you could run a test to ensure the flag catches all entries

110

13:40

<michaelfolkson> What are your thoughts on how this PR should progress @jnewbery? Suggest the flag on the PR?

111

13:41

<jkczyz> michaelfolkson: Was goind to say the same :)

112

13:41

<michaelfolkson> Or keep it in documentation?

113

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

114

13:41

<michaelfolkson> Or continue improving the PR as designed?

115

13:41

<jnewbery> I'm a concept ACK on the first commit, but a weak concept NACK on the second

116

13:42

<nehan> when i ran this, my debug.log had the following: 2019-08-14T15:56:58Z Warning: Unsupported logging category -debug=cmdline1.

117

13:42

<nehan> i couldn't track down why that was happening. do you know?

118

13:43

<jnewbery> the `-debug` argument takes one or more logging categories. cmdline1 is not a valid logging category

119

13:43

<nehan> ok, thanks. it wasn't in the log mentioned in https://github.com/bitcoin/bitcoin/pull/16115#issue-283090468

120

13:43

<jnewbery> the log came from here: https://github.com/bitcoin/bitcoin/blob/a7aa809027633556dd3280c6e29ca98eb3235a3d/src/init.cpp#L1005

121

13:43

<jnewbery> I suspect you'd see the same thing on master

122

13:44

<jnewbery> any other questions?

123

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?

124

13:45

<jnewbery> what do you mean 'before installing'?

125

13:45

<michaelfolkson> Some choices can't be reversed eg testnet choice, once pruned can't unprune

126

13:46

<michaelfolkson> Other choices can be changed later eg which nodes you connect to

127

13:46

<michaelfolkson> I don't know how many fit in that first category, probably not many

128

13:46

<jonatack> michaelfolkson: before IBD?

129

13:46

<michaelfolkson> Sorry yes

130

13:46

<jonatack> that seems like a great question

131

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.

132

13:47

<fjahr> you could do both on the same machine using the same bitcoind, with a different datadir

133

13:47

<jnewbery> There's also this, that might help you: https://jlopp.github.io/bitcoin-core-config-generator/

134

13:47

<jnewbery> (repo here: https://github.com/jlopp/bitcoin-core-config-generator)

135

13:48

<michaelfolkson> Yeah that is helpful. Doesn't address this currently

136

13:48

<michaelfolkson> That's good suggestion <fjahr>

137

13:48

<jonatack> maybe an initial node setup doc in the /doc dir

138

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

139

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)

140

13:49

<wumpus> prune because it throws away blocks, txindex because it's a huge amont of work to build the index

141

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

142

13:50

<jnewbery> I think prune is the important one

143

13:50

<wumpus> jnewbery: it's definitely become better

144

13:50

<jnewbery> any final questions, or are people happy to wrap it up there?

145

13:50

<wumpus> still txindex can take quite a long time too. that it happens in the background doesn't make it faster :)

146

13:50

<jonatack> michaelfolkson: this state of mind can be precious for adding docs

147

13:51

<jonatack> initial perspective

148

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

149

13:51

<michaelfolkson> Yeah should take advantage of it whilst I still have it ;)

150

13:52

<jnewbery> lots of great questions this week. Thanks everyone (and thanks wumpus for stopping by!)

151

13:52

<jnewbery> Here's your homework for next week:

152

13:52

<michaelfolkson> Yeah, was great. Thanks everyone

153

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

154

13:53

<jnewbery> - leave comments on this week's PR (https://github.com/bitcoin/bitcoin/pull/16115)

155

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

156

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 :)

157

13:54

<jnewbery> that's it. Thanks everyone!

158

13:54

<fjahr> thanks jnewbery

159

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 !