Skip to content

Relog configuration args on debug.log rotation #16673

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.

Sign up for GitHub

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

Jump to bottom
Closed
LarryRuane wants to merge 1 commit into from
Closed

Relog configuration args on debug.log rotation #16673

LarryRuane wants to merge 1 commit into from

Conversation

@LarryRuane
Copy link
Contributor

@LarryRuane LarryRuane commented Aug 20, 2019 •
edited
Loading

This PR was part of #16115 but reviewers requested that this be made into a separate PR. As explained in #16115, it's useful, maybe even crucial, for support, analysis, and debugging purposes for the configuration arguments to be present in the debug.log file, as that may be the only artifact provided to the developer or support team. That PR logs the configuration settings (command-line arguments and bitcoin.conf contents) when bitcoind starts. But sometime later, the debug log file may be "rotated" (a new debug.log file started so it doesn't grow unbounded in size) and this information would be lost unless the previous debug.log is preserved.

This PR re-logs the configuration information when the log rotates, ensuring that the current debug.log file contains this information. Reviewers had reservations about the previous approach (which you can see in #16115's discussion thread), so this PR implements this functionality in a simpler and (I believe) much better way.

@DrahtBot
Copy link
Contributor

DrahtBot commented Aug 21, 2019 •
edited
Loading

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #25614 (Severity-based logging, step 2 by jonatack)

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.

@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from fe88d65 to 410a617 Compare August 21, 2019 18:08
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from b217bf9 to d252dfe Compare August 21, 2019 20:18
practicalswift
practicalswift reviewed Aug 25, 2019
View reviewed changes
test/functional/test_framework/test_node.py Outdated
Copy link
Contributor

@practicalswift practicalswift Aug 25, 2019 •
edited
Loading

Choose a reason for hiding this comment

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

Do you really want unexpected_msgs to preserve parameter state between calls? :-)

>>> def foobar(foo, bar=[]):
...     bar.append(foo)
...     print(bar)
...
>>> foobar("hello")
['hello']
>>> foobar("hello")
['hello', 'hello']
>>> foobar("hello")
['hello', 'hello', 'hello']

I think this is what you want:

def assert_debug_log(self, expected_msgs, unexpected_msgs, timeout=2):
    if unexpected_msgs is None:
        unexpected_msgs = []

FWIW I think we should use a linter to guard against this Python gotcha :-)

Copy link
Contributor Author

@LarryRuane LarryRuane Aug 26, 2019

Choose a reason for hiding this comment

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

Great catch, I had no idea! I fixed this in #16115 (where it was introduced) and force-pushed rebased this PR onto that branch.

Copy link
Contributor Author

@LarryRuane LarryRuane Aug 29, 2019

Choose a reason for hiding this comment

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

@practicalswift, I don't think this was an actual problem. I added a debug print and unexpected_msgs didn't include previous values. I think it's not broken because this function, assert_debug_log(), doesn't modify the variable (it's not mutable). Here's an extremely simplified version of this function and some sample calls to it:

def assert_debug_log(unexpected_msgs=[]):
    print(unexpected_msgs)
    for unexpected_msg in unexpected_msgs:
        print('  ', unexpected_msg)

assert_debug_log()
assert_debug_log(["foo"])
assert_debug_log(unexpected_msgs=["foo"])
assert_debug_log("bar") # not actually called this way but just curious
assert_debug_log()

The output:

[]
['foo']
   foo
['foo']
   foo
bar
   b
   a
   r
[]

What prompted me to investigate this further is that I wondered if any of our existing python code has this problem. I found just one instance, which is in wallet_importmulti.py:

def test_importmulti(self, req, success, error_code=None, error_message=None, warnings=[]):

But adding a debug print to that function showed everything was okay. I believe that's because warnings isn't modified in that function.

@LarryRuane LarryRuane mentioned this pull request Aug 26, 2019
Merged
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from d252dfe to 5b413fd Compare August 26, 2019 03:45
@practicalswift practicalswift mentioned this pull request Aug 26, 2019
Merged
maflcko pushed a commit that referenced this pull request Aug 28, 2019
Merge #16726: tests: Avoid common Python default parameter gotcha whe…
cc40b55 
…n mutable dict/list:s are used as default parameter values

e4f4ea4 lint: Catch use of [] or {} as default parameter values in Python functions (practicalswift)
25dd867 Avoid using mutable default parameter values (practicalswift)

Pull request description:

  Avoid common Python default parameter gotcha when mutable `dict`/`list`:s are used as default parameter values.

  Examples of this gotcha caught during review:
  * #16673 (comment)
  * #14565 (comment)

  Perhaps surprisingly this is how mutable list and dictionary default parameter values behave in Python:

  ```
  >>> def f(i, j=[], k={}):
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1, 1], {1: True})
  >>> f(2)
  ([1, 1, 2], {1: True, 2: True})
  ```

  In contrast to:

  ```
  >>> def f(i, j=None, k=None):
  ...     if j is None:
  ...         j = []
  ...     if k is None:
  ...         k = {}
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1], {1: True})
  >>> f(2)
  ([2], {2: True})
  ```

  The latter is typically the intended behaviour.

  This PR fixes two instances of this and adds a check guarding against this gotcha going forward :-)

ACKs for top commit:
  Sjors:
    Oh Python... ACK e4f4ea4. Testing tip: swap the two commits.

Tree-SHA512: 56e14d24fc866211a20185c9fdb274ed046c3aed2dc0e07699e58b6f9fa3b79f6d0c880fb02d72b7fe5cc5eb7c0ff6da0ead33123344e1a872209370c2e49e3f
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Aug 28, 2019
@sidhujag
Merge bitcoin#16726: tests: Avoid common Python default parameter got…
20a512a 
…cha when mutable dict/list:s are used as default parameter values

e4f4ea4 lint: Catch use of [] or {} as default parameter values in Python functions (practicalswift)
25dd867 Avoid using mutable default parameter values (practicalswift)

Pull request description:

  Avoid common Python default parameter gotcha when mutable `dict`/`list`:s are used as default parameter values.

  Examples of this gotcha caught during review:
  * bitcoin#16673 (comment)
  * bitcoin#14565 (comment)

  Perhaps surprisingly this is how mutable list and dictionary default parameter values behave in Python:

  ```
  >>> def f(i, j=[], k={}):
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1, 1], {1: True})
  >>> f(2)
  ([1, 1, 2], {1: True, 2: True})
  ```

  In contrast to:

  ```
  >>> def f(i, j=None, k=None):
  ...     if j is None:
  ...         j = []
  ...     if k is None:
  ...         k = {}
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1], {1: True})
  >>> f(2)
  ([2], {2: True})
  ```

  The latter is typically the intended behaviour.

  This PR fixes two instances of this and adds a check guarding against this gotcha going forward :-)

ACKs for top commit:
  Sjors:
    Oh Python... ACK e4f4ea4. Testing tip: swap the two commits.

Tree-SHA512: 56e14d24fc866211a20185c9fdb274ed046c3aed2dc0e07699e58b6f9fa3b79f6d0c880fb02d72b7fe5cc5eb7c0ff6da0ead33123344e1a872209370c2e49e3f
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 5b413fd to 34c97d7 Compare September 5, 2019 15:23
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 34c97d7 to c0fa4be Compare October 25, 2019 14:21
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from c0fa4be to 339a1e3 Compare November 21, 2019 23:05
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 339a1e3 to 6a008dd Compare December 13, 2019 17:46
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 6a008dd to 1375f89 Compare December 20, 2019 21:36
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 1375f89 to 3fe5ba8 Compare December 23, 2019 17:45
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 3fe5ba8 to 773660c Compare January 19, 2020 18:35
LarryRuane
LarryRuane commented Jan 19, 2020
View reviewed changes
Copy link
Contributor Author

@LarryRuane LarryRuane left a comment

Choose a reason for hiding this comment

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

Force-pushed after rebasing onto #16115

@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 773660c to fc7c03c Compare January 20, 2020 17:36
@DrahtBot DrahtBot mentioned this pull request Apr 20, 2021
Merged
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from f0ce638 to 20dbb95 Compare April 24, 2021 03:35
@LarryRuane
Copy link
Contributor Author

LarryRuane commented Apr 24, 2021

Force-pushed required rebase. I should have mentioned earlier that you can test this manually by starting bitcoind, waiting for it to start up and sync, and then running:

kill -SIGHUP `pgrep bitcoind`

Then check debug.log; the version information and configuration settings should appear at the end. (You can do that kill repeatedly, and the information will appear again each time.)

A more realistic test is is to do actual log rotation: Start bitcoind, wait for it to start up, then

mv ~/.bitcoin/debug.log ~/.bitcoin/debug.log.old

(Note that in this state, additional logging will go to debug.log.old; the new debug.log won't exist.)

Then send the signal. A new debug.log will be created containing the version and configuration information. Further logging will appear there (and not to debug.log.old). The intention is that debug.log.old can be compressed, or archived (or deleted) or whatever. (See man logrotate.)

@DrahtBot DrahtBot mentioned this pull request Jun 27, 2021
Closed
@rebroad
Copy link
Contributor

rebroad commented Nov 21, 2021

NACK - does not seem useful or necessary (given the previous logs can be referred to easily).

@LarryRuane
Copy link
Contributor Author

LarryRuane commented Nov 21, 2021

NACK - does not seem useful or necessary (given the previous logs can be referred to easily).

Well, if it's not useful or necessary, I don't think it's for this reason, because an external log rotation agent (see logrotate on Unix-like systems, for example) may have deleted the initial part of the debug.log file for the currently-running instance of bitcoind that contains the configuration information (which does get logged at startup).

@rebroad
Copy link
Contributor

rebroad commented Nov 25, 2021

NACK - does not seem useful or necessary (given the previous logs can be referred to easily).

Well, if it's not useful or necessary, I don't think it's for this reason, because an external log rotation agent (see logrotate on Unix-like systems, for example) may have deleted the initial part of the debug.log file for the currently-running instance of bitcoind that contains the configuration information (which does get logged at startup).

ah, I see.. yes, in that case this might be useful, but I think it's better if it's optional - or you could just use a logrotate script to save this part of the debug.log file elsewhere before it deletes the file.

This was referenced Mar 2, 2022
Closed
Merged
@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 20dbb95 to 4eededb Compare August 2, 2022 18:51
@LarryRuane
Copy link
Contributor Author

LarryRuane commented Aug 2, 2022

Force-pushed rebase, and made a few improvements.

@LarryRuane LarryRuane force-pushed the relog-args-on-rotation branch from 4eededb to a4e6c45 Compare August 2, 2022 21:58
@DrahtBot DrahtBot mentioned this pull request Aug 4, 2022
Merged
@DrahtBot
Copy link
Contributor

DrahtBot commented Sep 1, 2022

🐙 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".

@achow101
Copy link
Member

achow101 commented Oct 12, 2022

Closing this as it has not had any activity in a while. If you are interested in continuing work on this, please leave a comment so that it can be reopened.

@achow101 achow101 closed this Oct 12, 2022
knst pushed a commit to knst/dash that referenced this pull request Feb 28, 2023
@knst
Merge bitcoin#16726: tests: Avoid common Python default parameter got…
4507ba2 
…cha when mutable dict/list:s are used as default parameter values

e4f4ea4 lint: Catch use of [] or {} as default parameter values in Python functions (practicalswift)
25dd867 Avoid using mutable default parameter values (practicalswift)

Pull request description:

  Avoid common Python default parameter gotcha when mutable `dict`/`list`:s are used as default parameter values.

  Examples of this gotcha caught during review:
  * bitcoin#16673 (comment)
  * bitcoin#14565 (comment)

  Perhaps surprisingly this is how mutable list and dictionary default parameter values behave in Python:

  ```
  >>> def f(i, j=[], k={}):
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1, 1], {1: True})
  >>> f(2)
  ([1, 1, 2], {1: True, 2: True})
  ```

  In contrast to:

  ```
  >>> def f(i, j=None, k=None):
  ...     if j is None:
  ...         j = []
  ...     if k is None:
  ...         k = {}
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1], {1: True})
  >>> f(2)
  ([2], {2: True})
  ```

  The latter is typically the intended behaviour.

  This PR fixes two instances of this and adds a check guarding against this gotcha going forward :-)

ACKs for top commit:
  Sjors:
    Oh Python... ACK e4f4ea4. Testing tip: swap the two commits.

Tree-SHA512: 56e14d24fc866211a20185c9fdb274ed046c3aed2dc0e07699e58b6f9fa3b79f6d0c880fb02d72b7fe5cc5eb7c0ff6da0ead33123344e1a872209370c2e49e3f
PastaPastaPasta pushed a commit to knst/dash that referenced this pull request Apr 4, 2023
@PastaPastaPasta
Merge bitcoin#16726: tests: Avoid common Python default parameter got…
a84ec5c 
…cha when mutable dict/list:s are used as default parameter values

e4f4ea4 lint: Catch use of [] or {} as default parameter values in Python functions (practicalswift)
25dd867 Avoid using mutable default parameter values (practicalswift)

Pull request description:

  Avoid common Python default parameter gotcha when mutable `dict`/`list`:s are used as default parameter values.

  Examples of this gotcha caught during review:
  * bitcoin#16673 (comment)
  * bitcoin#14565 (comment)

  Perhaps surprisingly this is how mutable list and dictionary default parameter values behave in Python:

  ```
  >>> def f(i, j=[], k={}):
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1, 1], {1: True})
  >>> f(2)
  ([1, 1, 2], {1: True, 2: True})
  ```

  In contrast to:

  ```
  >>> def f(i, j=None, k=None):
  ...     if j is None:
  ...         j = []
  ...     if k is None:
  ...         k = {}
  ...     j.append(i)
  ...     k[i] = True
  ...     return j, k
  ...
  >>> f(1)
  ([1], {1: True})
  >>> f(1)
  ([1], {1: True})
  >>> f(2)
  ([2], {2: True})
  ```

  The latter is typically the intended behaviour.

  This PR fixes two instances of this and adds a check guarding against this gotcha going forward :-)

ACKs for top commit:
  Sjors:
    Oh Python... ACK e4f4ea4. Testing tip: swap the two commits.

Tree-SHA512: 56e14d24fc866211a20185c9fdb274ed046c3aed2dc0e07699e58b6f9fa3b79f6d0c880fb02d72b7fe5cc5eb7c0ff6da0ead33123344e1a872209370c2e49e3f
@bitcoin bitcoin locked and limited conversation to collaborators Oct 12, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Reviewers

1 more reviewer

@practicalswift practicalswift practicalswift left review comments

Reviewers whose approvals may not affect merge requirements

Assignees

No one assigned

Labels

Needs rebase Utils/log/libs

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

7 participants

@LarryRuane @DrahtBot @jonatack @rebroad @achow101 @practicalswift @fanquake