Relog configuration args on debug.log rotation #16673

pull LarryRuane wants to merge 1 commits into bitcoin:master from LarryRuane:relog-args-on-rotation changing 6 files +144 −32
  1. LarryRuane commented at 11:07 pm on August 20, 2019: contributor

    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.

  2. fanquake added the label Utils/log/libs on Aug 20, 2019
  3. DrahtBot commented at 3:01 am on August 21, 2019: contributor

    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.

  4. DrahtBot added the label Needs rebase on Aug 21, 2019
  5. LarryRuane force-pushed on Aug 21, 2019
  6. DrahtBot removed the label Needs rebase on Aug 21, 2019
  7. LarryRuane force-pushed on Aug 21, 2019
  8. in test/functional/test_framework/test_node.py:310 in d252dfe814 outdated 
    306@@ -307,7 +307,7 @@ def wait_until_stopped(self, timeout=BITCOIND_PROC_WAIT_TIMEOUT):
307         wait_until(self.is_node_stopped, timeout=timeout)
308 
309     @contextlib.contextmanager
310-    def assert_debug_log(self, expected_msgs, timeout=2):
311+    def assert_debug_log(self, expected_msgs, unexpected_msgs=[], timeout=2):
    practicalswift commented at 9:18 pm on August 25, 2019:

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

    0>>> def foobar(foo, bar=[]):
1...     bar.append(foo)
2...     print(bar)
3...
4>>> foobar("hello")
5['hello']
6>>> foobar("hello")
7['hello', 'hello']
8>>> foobar("hello")
9['hello', 'hello', 'hello']

    I think this is what you want:

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

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

    LarryRuane commented at 3:48 am on August 26, 2019:
    Great catch, I had no idea! I fixed this in #16115 (where it was introduced) and force-pushed rebased this PR onto that branch.
    LarryRuane commented at 8:27 pm on August 29, 2019:

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

    0def assert_debug_log(unexpected_msgs=[]):
1    print(unexpected_msgs)
2    for unexpected_msg in unexpected_msgs:
3        print('  ', unexpected_msg)
4
5assert_debug_log()
6assert_debug_log(["foo"])
7assert_debug_log(unexpected_msgs=["foo"])
8assert_debug_log("bar") # not actually called this way but just curious
9assert_debug_log()

    The output:

    0[]
1['foo']
2   foo
3['foo']
4   foo
5bar
6   b
7   a
8   r
9[]

    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:

    0def 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.

  9. LarryRuane force-pushed on Aug 26, 2019
  10. maflcko referenced this in commit cc40b55da7 on Aug 28, 2019
  11. sidhujag referenced this in commit 20a512ab44 on Aug 28, 2019
  12. DrahtBot added the label Needs rebase on Sep 5, 2019
  13. LarryRuane force-pushed on Sep 5, 2019
  14. DrahtBot removed the label Needs rebase on Sep 5, 2019
  15. DrahtBot added the label Needs rebase on Oct 16, 2019
  16. LarryRuane force-pushed on Oct 25, 2019
  17. DrahtBot removed the label Needs rebase on Oct 25, 2019
  18. LarryRuane force-pushed on Nov 21, 2019
  19. DrahtBot added the label Needs rebase on Dec 13, 2019
  20. LarryRuane force-pushed on Dec 13, 2019
  21. DrahtBot removed the label Needs rebase on Dec 13, 2019
  22. DrahtBot added the label Needs rebase on Dec 19, 2019
  23. LarryRuane force-pushed on Dec 20, 2019
  24. DrahtBot removed the label Needs rebase on Dec 20, 2019
  25. LarryRuane force-pushed on Dec 23, 2019
  26. LarryRuane force-pushed on Jan 19, 2020
  27. LarryRuane commented at 6:51 pm on January 19, 2020: contributor
    Force-pushed after rebasing onto https://github.com/bitcoin/bitcoin/pull/16115
  28. LarryRuane force-pushed on Jan 20, 2020
  29. DrahtBot added the label Needs rebase on Jan 29, 2020
  30. LarryRuane force-pushed on Jan 31, 2020
  31. DrahtBot removed the label Needs rebase on Jan 31, 2020
  32. LarryRuane force-pushed on Feb 18, 2020
  33. LarryRuane commented at 5:32 pm on February 18, 2020: contributor
    Rebased onto latest master
  34. DrahtBot added the label Needs rebase on May 28, 2020
  35. LarryRuane force-pushed on May 28, 2020
  36. DrahtBot removed the label Needs rebase on May 28, 2020
  37. LarryRuane force-pushed on Jul 12, 2020
  38. LarryRuane commented at 0:45 am on July 13, 2020: contributor
    Force-pushed merge conflict fixes. I believe all reviewer comments have been addressed; no more work planned, this PR can be merged if desired.
  39. monstrobishi referenced this in commit dfb35e0a17 on Jul 30, 2020
  40. ShengguangXiao referenced this in commit f1b90146b1 on Aug 28, 2020
  41. DrahtBot added the label Needs rebase on Feb 18, 2021
  42. LarryRuane force-pushed on Mar 3, 2021
  43. jonatack commented at 10:48 pm on March 3, 2021: contributor
    Concept ACK. I’m a fan of the original feature that logs the config options to the debug log.
  44. DrahtBot removed the label Needs rebase on Mar 3, 2021
  45. DrahtBot added the label Needs rebase on Apr 23, 2021
  46. LarryRuane force-pushed on Apr 24, 2021
  47. LarryRuane commented at 3:48 am on April 24, 2021: contributor

    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:

    0kill -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

    0mv ~/.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.)

  48. DrahtBot removed the label Needs rebase on Apr 24, 2021
  49. rebroad commented at 4:46 pm on November 21, 2021: contributor
    NACK - does not seem useful or necessary (given the previous logs can be referred to easily).
  50. LarryRuane commented at 5:28 pm on November 21, 2021: contributor

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

  51. rebroad commented at 1:13 pm on November 25, 2021: contributor

    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.

  52. DrahtBot added the label Needs rebase on May 24, 2022
  53. LarryRuane force-pushed on Aug 2, 2022
  54. LarryRuane commented at 7:04 pm on August 2, 2022: contributor
    Force-pushed rebase, and made a few improvements.
  55. DrahtBot removed the label Needs rebase on Aug 2, 2022
  56. util: relog configuration arguments when debug.log rotates a4e6c45238
  57. LarryRuane force-pushed on Aug 2, 2022
  58. DrahtBot added the label Needs rebase on Sep 1, 2022
  59. DrahtBot commented at 9:18 pm on September 1, 2022: contributor

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

  60. achow101 commented at 6:01 pm on October 12, 2022: member
    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.
  61. achow101 closed this on Oct 12, 2022
  62. knst referenced this in commit 4d794e027c on Feb 13, 2023
  63. knst referenced this in commit 45d58d93ed on Feb 13, 2023
  64. knst referenced this in commit 16ad65a17c on Feb 28, 2023
  65. knst referenced this in commit 4507ba2728 on Feb 28, 2023
  66. knst referenced this in commit 3c2ab6c42b on Mar 14, 2023
  67. knst referenced this in commit 1fad1541e8 on Mar 15, 2023
  68. PastaPastaPasta referenced this in commit a84ec5cc19 on Apr 4, 2023
  69. bitcoin locked this on Oct 12, 2023


LarryRuane DrahtBot practicalswift jonatack rebroad achow101

Labels
Utils/log/libs Needs rebase

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-07-03 10:13 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me