On bitcoind startup, write config args to debug.log (
utils/log/libs) Aug 14, 2019
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.
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 (
)? What are your thoughts about that additional functionality? re-log configuration when debug.log is reopened What tests are included in this PR? Could any additional tests be added?
8 13:01 <jnewbery> jkczyz: I see you already left review comments. Great!
9 13:01 <jnewbery> What were your overall thoughts on the PR?
10 13:02 <jnewbery> (open to anyone)
11 13:02 <digi_james> Hello
12 13:02 <jkczyz> Undecided if this is preferable to a command to print the args
13 13:03 <jnewbery> I think there's a PR that does that (RPC to print args) too
14 13:04 <jonatack> seems somewhat brittle, unfinished, and needs more test coverage
15 13:04 <jonatack> though good idea
16 13:04 <fjahr> Yeah, #15493 is the PR for print args
17 13:04 <jnewbery> jonatack: what part do you think is brittle
18 13:05 <jonatack> the blacklist part
20 13:05 <jnewbery> fjahr: I don't think that's an RPC. That's a command line arg to pass to bitcoind
21 13:05 <michaelfolkson> I wasn't sure on the Concept ACK
22 13:05 <jnewbery> maybe 15493 was the one I was thinking of
23 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).
24 13:06 <jnewbery> jkczyz: can you think of any advantage to logging to debug.log instead of an RPC?
25 13:06 <jonatack> jtczyz: yes, nice job on the review
26 13:07 <fjahr> jnewbery: that's the same number?
27 13:07 <jkczyz> jnewbery: Yeah, in cases where there is a crash under the given configuration
28 13:07 <jnewbery> fjahr: yes, I think I misremembered what that PR was doing
29 13:07 <fjahr> ah, got it
30 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
31 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
32 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
33 13:09 <michaelfolkson> Surely better to provide them separately
34 13:10 <jnewbery> michaelfolkson: (re: are we expecting them...) perhaps, but better to log somewhere than nowhere
35 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?
36 13:11 <michaelfolkson> Provide two different logs? You only need the recent output to see what the problem was in the debug log
37 13:11 <nehan> i assumed he meant the values for all commandline arguments instead of just user-passed in ones
38 13:12 <jnewbery> nehan: that's part of it
39 13:12 <nehan> as promag points out that seems difficult because initialization happens all over the place
40 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
41 13:13 <jnewbery> there are also commandline args that interact with each other, so if one is set then it affects others
43 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
44 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?
46 13:15 <nehan> it would be easy for someone adding a sensitive argument to forget to update that blacklist
47 13:16 <jnewbery> nehan: I agree!
48 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.
49 13:16 <jnewbery> any suggestions on a different implementation?
50 13:17 <jnewbery> nehan: good idea
51 13:17 <jonatack> a whitelist would be safer, though probably more involved
52 13:17 <jkczyz> Perhaps it could be built into the arg code. A bit saying if it should be blacklisted
53 13:17 <probably_dillon> a whitelist would suffer from the same "and what if someone forgets it?" problem
54 13:17 <fjahr> there should be a explicit declaration on each argument
55 13:17 <jnewbery> jonatack: yes. It suffers from the same problem (people forgetting to update it), but the impact is probably less bad
56 13:18 <jonatack> yes, not the same probable consequences
57 13:18 <fjahr> not when calling it, I mean as a type of something like taht in the code
60 13:20 <jnewbery> next question: What is Bitcoin Core log shrinking? Where is it implemented?
61 13:20 <nehan> ShrinkDebugFile() in logging.cpp
62 13:20 <jkczyz> Truncates start of log file if it grows too large (over 10MB * 110% = 11MB)
63 13:21 <michaelfolkson> Only on startup
64 13:21 <lightlike> called in init at startup (before logging anything else)
65 13:21 <jnewbery> nehan, jkczyz, michaelfolkson, lighlike: great answers :)
66 13:21 <jnewbery> any questions on what that's doing?
67 13:22 <michaelfolkson> What was the rationale for only shrinking on startup?
68 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?
69 13:23 <michaelfolkson> Addresses problem of not shrinking the log after startup
70 13:23 <jkczyz> A tool for limiting the size of log files by breaking into multiple files
72 13:24 <jnewbery> jkczyz: right. Did you find where support for log rotation was added to bitcoin core?
73 13:25 <probably_dillon> is there something wrong with just relying a system's logrotate?
74 13:25 <jkczyz> jnewbery: I did not. Just assumed people used external tools for it
75 13:26 <jkczyz> jnewbery: I think I saw a PR where someone wanted to add it, though
76 13:26 <jnewbery> probably_dillon: that's exactly what happens. bitcoind does not rotate its own log files
79 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....
80 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?"
81 13:28 <nehan> 1) 200 seems arbitrary 2) I think the logrotator should support saving the startup log instead of doing this
82 13:29 <jnewbery> nehan: I agree with both of those
83 13:29 <nehan> now someone has to think about whether or not to put information into this special re-log thing
84 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.
85 13:30 <probably_dillon> nehan: do you mean implementing this as a new "boot config log" log?
86 13:30 <jnewbery> I also didn't like the fact that the log timestamps are no longer monotonic after this PR
87 13:30 <jnewbery> That's probably going to confuse some log parsers
88 13:31 <nehan> probably_di: i don't think saving (or reprinting) initial log information should be handled in bitcoind
89 13:31 <jonatack> nehan: agreed. brittle.
90 13:32 <jkczyz> If args are logged at startup, it might be useful providing docs on how to configure the logrotate properly
91 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
93 13:34 <jnewbery> ok, final question: What tests are included in this PR? Could any additional tests be added?
94 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 ****.
95 13:35 <fjahr> a functional test that is called unit test in the commit message
96 13:35 <jkczyz> could include a test for blacklisted args with '-regtest.' or other such prefixes
97 13:35 <jonatack> For one, I'd like to see some edge cases tested as well.
98 13:36 <michaelfolkson> Such as?
99 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)
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
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
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
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 !
160 13:54 <wumpus> yes thanks everyone
161 13:55 <lightlike> thanks!
162 13:55 <michaelfolkson> Ah it is an issue <jnewbery>. I was looking for that a couple of weeks ago haha
163 13:55 <jkczyz> yeah, good session!
164 13:55 <jonatack> jnewbery, wumpus: thanks! ... thanks, everyone!
165 13:55 <fanquake> That PSBT shuffle inputs PR will be a good one.