Add `-debuglogfile` option #11781

laanwj · 2017-11-28T09:36:31Z

This patch adds an option to configure the name and/or directory of the debug log file.

The user can specify either a relative path, in which case the path is relative to the (network specific) data directory. They can also specify an absolute path to put the log anywhere else in the file system.

Alternative to #11741 that gets rid of the concept of a "log directory" by specifying the path for the specific kind of log, the debug log. Which happens to be the only kind of log we have at this point*, but a hypothetical new kind of log (say, an audit log) would get a new option. This has more flexibility than specifying a directory which has to contain all of them.

* excluding db.log which is internally generated by the wallet database library, but that one moves along with -walletdir.

promag · 2017-11-28T10:29:08Z

Can't test right now, but what happens if the absolute path doesn't exist?

laanwj · 2017-11-28T10:31:41Z

Can't test right now, but what happens if the absolute path doesn't exist?

bitcoind: /home/orion/projects/bitcoin/bitcoin/src/util.cpp:359: int LogPrintStr(const std::string &): Assertion `vMsgsBeforeOpenLog' failed.
Aborted (core dumped)

Gah, seems like we need a check in init before the logging stuff is initialized.

promag · 2017-11-28T10:35:59Z

Right, current code knows that data dir exists.

promag · 2017-11-28T10:37:05Z

If you do handle that, then add an init test for inexistent path.

laanwj · 2017-11-28T10:38:21Z

@promag Apparently there is some logic for handling the case that the debug log could not be opened: https://github.com/bitcoin/bitcoin/blob/master/src/util.cpp#L201 . So it's a matter of passing it on to the caller.

laanwj · 2017-11-28T11:06:38Z

Pushed error handling when the log file could not be opened.

$ src/bitcoind -testnet -debuglogfile=/dfdf                                                                                                             
Error: Could not open debug log file /dfdf

(currently this segfaults afterwards, but that is due to an unrelated problem introduced in #10286, see #11783)

PR bitcoin#10286 introduced a few steps which are not robust to early shutdown in initialization. Stumbled upon this with bitcoin#11781, not sure if there are other scenarios that can trigger it, but it's harden against this in any case.

promag

utACK 2501383.

Care to update release notes? At least add tag.

promag · 2017-11-28T12:12:26Z

src/init.cpp

-        OpenDebugLog();
+    if (fPrintToDebugLog) {
+        if (!OpenDebugLog()) {
+            return InitError(strprintf("Could not open debug log file %s", GetDebugLogPath().string()));


Nit, missing test.

Will add a test, though testing this particular message only makes sense after #11783 goes in

Added test anyway, temporarily adding "Fix shutdown in case of errors during initialization" into here

promag · 2017-11-28T12:54:47Z

src/init.cpp

@@ -342,6 +342,7 @@ std::string HelpMessage(HelpMessageMode mode)
    if (showDebug)
        strUsage += HelpMessageOpt("-feefilter", strprintf("Tell other nodes to filter invs to us by our mempool min fee (default: %u)", DEFAULT_FEEFILTER));
    strUsage += HelpMessageOpt("-loadblock=<file>", _("Imports blocks from external blk000??.dat file on startup"));
+    strUsage += HelpMessageOpt("-debuglogfile=<dir>", _("Specify location of debug log file (default: debug.log in datadir)"));


Fix =<dir>.

Thanks, done

jonasschnelli · 2017-11-28T19:35:54Z

utACK ad4e94a4aa8cebfa2147c47cd57098a2901b3e62

For me, it was not clear from the release notes and the init.cpp help line that one can use absolute paths (but maybe it's obvious).
What if someone uses -debuglogfile=wallet.dat?

promag

Tested ACK.

What if someone uses -debuglogfile=wallet.dat?

It will corrupt the db by appending the log and eventually rotate the content. Later we could only an existing file if it is text/plain?

promag · 2017-11-28T22:19:54Z

test/functional/loggingtest.py

+
+        # check that invalid log (relative) will cause error
+        self.stop_node(0)
+        self.assert_start_raises_init_error(0, ["-debuglogfile=ssdksjdf/sdasdfa/sdfsdfsfd"],


Replace with foo/foo.log? (before squash).

Why? any invalid filename will do equally and this is as likely to stay invalid as anything.

Below you use foo/foo.log, not shydhehhaghdhdjs.

That's a different test case, there's no need for them to use the same (non-existent) file name.

It's the only keyboard mashing in the codebase, by the looks? Something like "-debuglogfile=no/path/for/debug.log" or similar seems like it would be clearer. Having a similar path for both relative and absolute cases would make it a bit more obvious what the key difference that's being tested is too.

promag · 2017-11-28T22:23:18Z

test/functional/loggingtest.py

+        self.assert_start_raises_init_error(0, ["-debuglogfile=%s" % invalidname],
+                "Error: Could not open debug log file")
+
+


~~Nit, remove 2nd empty line.~~

From PEP 8:

Blank Lines

Surround top-level function and class definitions with two blank lines.

promag · 2017-11-28T22:26:22Z

test/functional/loggingtest.py

+
+from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import assert_equal
+import os


Nit, from PEP 8:

Imports should be grouped in the following order:

standard library imports

related third party imports

local application/library specific imports

You should put a blank line between each group of imports.

Example:

bitcoin/test/functional/multiwallet.py

Lines 5 to 16 in 26efc22

"""Test multiwallet.

Verify that a bitcoind node can load multiple wallet files

"""

import os

import shutil

from test_framework.test_framework import BitcoinTestFramework

from test_framework.util import assert_equal, assert_raises_rpc_error

class MultiWalletTest(BitcoinTestFramework):

def set_test_params(self):

I literally copied this from another test (uacomment.py), so it should be consistent at least. PEP8 compliance is not really my goal, sorry.

My personal preference is to follow pep8 convention. I agree that it doesn't make sense to go and change all existing tests, but when adding new tests there's no harm in following the standard convention.

uacomment.py doesn't import any standard libraries, so pep8 import ordering isn't a consideration for that test.

promag · 2017-11-29T01:10:23Z

µnit, just test/functional/logging.py?

laanwj · 2017-11-29T08:16:08Z

It will corrupt the db by appending the log and eventually rotate the content. Later we could only an existing file if it is text/plain?

I guess it could do a berkeleydb magic check (from #11485) before opening the log for appending, but I'm not going to do so in this PR.

At least the walletdir makes it less likely people will overwrite an existing wallet. You can't 100% prevent people from overwriting wallets.

test/functional/logging.py

I first had it named by that, but renamed it to this because logging.py is more easily confused with logging of the test framework.

promag · 2017-11-29T08:29:13Z

I think this is good as it is.

laanwj · 2017-11-29T09:02:23Z

For me, it was not clear from the release notes and the init.cpp help line that one can use absolute paths (but maybe it's obvious).

Couldn't hurt mentioning it, I agree, will add it, though I don't think we mention this for any other options. Maybe we should though... for many options it's clear you can use an absolute path, but it's quite unclear what a relative path even does.

laanwj · 2017-11-29T10:10:00Z

Ok, updated the message (as well as added DEFAULT_DEBUGLOGFILE constant) and squashed

promag · 2017-11-29T14:38:26Z

re-Tested ACK b382a24.

jnewbery

Tested ACK b382a246dafbb1895c66445bef2a5aac595933de with just a few nits

jnewbery · 2017-11-29T18:03:41Z

doc/release-notes.md

@@ -90,6 +90,9 @@ Low-level RPC changes
  * `getmininginfo`
 - The wallet RPC `getreceivedbyaddress` will return an error if called with an address not in the wallet.

+Changed command-line options
+-----------------------------
+- `-debuglogfile=<file>` can be used to specify an alternative debug logging file.


Can you update the text to say that this can be absolute or relative (just like you have for the help text: this can be an absolute path or a path relative to the data directory)?

The release notes are not documentation. This minor change does not warrant a long write-up in the release notes. If anyone wants to have documentation they can just look at bitcoind's help which is documentation.

jnewbery · 2017-11-29T18:13:23Z

test/functional/loggingtest.py

+
+from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import assert_equal
+import os


My personal preference is to follow pep8 convention. I agree that it doesn't make sense to go and change all existing tests, but when adding new tests there's no harm in following the standard convention.

uacomment.py doesn't import any standard libraries, so pep8 import ordering isn't a consideration for that test.

jnewbery · 2017-11-29T18:13:33Z

test/functional/loggingtest.py

+"""Test debug logging."""
+
+from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import assert_equal


imported but unused

jnewbery · 2017-11-29T18:15:29Z

test/functional/loggingtest.py

+        # check that invalid log (relative) will cause error
+        self.stop_node(0)
+        self.assert_start_raises_init_error(0, ["-debuglogfile=ssdksjdf/sdasdfa/sdfsdfsfd"],
+                "Error: Could not open debug log file")


nit: pep8 convention would have this continuation line aligned with the opening parens of the line above, ie:

self.assert_start_raises_init_error(0, ["-debuglogfile=ssdksjdf/sdasdfa/sdfsdfsfd"], "Error: Could not open debug log file")

again, this is more personal preference than a fast rule.

jonasschnelli · 2017-11-29T19:11:36Z

utACK b382a246dafbb1895c66445bef2a5aac595933de.
I don't really care about PEP.

jnewbery · 2017-11-29T19:41:56Z

I don't really care about PEP.

I appreciate I may be in the minority here, but some reasoning for why I think it's a good idea to follow standard style conventions (at least when introducing new code):

having a canonical ordering for imports makes scanning much quicker for anyone reading the code.
people who have worked on other projects may be used to following PEP8, so will feel more comfortable when starting to contribute to this project. This import ordering is not only specified in PEP8, but also in the google python coding standard:
https://google.github.io/styleguide/pyguide.html?showone=Imports_formatting#Imports_formatting and other style guides
it's good practice to always run a linter over the file whenever you save. That doesn't only highlight style nits, but also catches genuine bugs and makes it much less likely that you'll introduce a hard-to-track-down bug. Only committing files when they're free of lint warnings is a good safeguard against introducing unnecessary bugs.

https://stackoverflow.com/a/20763446/933705 has more rationale for import ordering.

Code is read far more than it's written, so a better question than 'why?' is 'why not?'. A small amount of effort now makes it easier for all future readers of the code to understand the intent.

jonasschnelli · 2017-11-29T20:19:11Z

@jnewbery. I generally agree.

The point I'm trying to make is that we tend to loose important focus or time with minor code ordering discussions. I think we should make contributors aware of the recommended rules and standard but then, at the same time, let it go a bit for the sake of focus on the important stuff.

Though I don't want to advocate bad code quality with this.

…tion d31e5c1 Fix shutdown in case of errors during initialization (Wladimir J. van der Laan) Pull request description: PR bitcoin#10286 introduced a few steps which are not robust to early shutdown in initialization. Stumbled upon this with bitcoin#11781, not sure if there are other scenarios that can trigger it, but it's good to harden against this in any case. E.g. ``` $ src/bitcoind -debuglogfile=/dfdf Error: Could not open debug log file /dfdf Program received signal SIGSEGV, Segmentation fault. UnregisterValidationInterface (pwalletIn=0x0) at /.../bitcoin/src/validationinterface.cpp:82 82 g_signals.m_internals->BlockChecked.disconnect(boost::bind(&CValidationInterface::BlockChecked, pwalletIn, _1, _2)); (gdb) bt #0 UnregisterValidationInterface (pwalletIn=0x0) at /.../bitcoin/src/validationinterface.cpp:82 #1 0x00005555555a11fc in Shutdown () at /.../bitcoin/src/init.cpp:196 #2 0x00005555555961cc in AppInit (argc=<optimized out>, argv=<optimized out>) at /.../bitcoin/src/bitcoind.cpp:183 #3 0x0000555555596249 in main (argc=0, argv=0x555555ecf200) at /.../bitcoin/src/bitcoind.cpp:19 ``` Tree-SHA512: 7dd9570a9803514a17781bfadf1edde47e96df4e852cce2f423cab422e005fb94d44e777af1a6ea5167b04a4d889e848ae7a61a7e0e94232247ddea32ee70fc8

5a7c09a test: Add tests for `-debuglogfile` with subdirs (Anthony Towns) 4158734 doc: Update release notes for `-debuglogfile` (Wladimir J. van der Laan) 2323242 test: Add test for `-debuglogfile` (Wladimir J. van der Laan) cf5f432 Add `-debuglogfile` option (Wladimir J. van der Laan) Pull request description: This patch adds an option to configure the name and/or directory of the debug log file. The user can specify either a relative path, in which case the path is relative to the (network specific) data directory. They can also specify an absolute path to put the log anywhere else in the file system. Alternative to bitcoin#11741 that gets rid of the concept of a "log directory" by specifying the path for the specific kind of log, the debug log. Which happens to be the only kind of log we have at this point*, but a hypothetical new kind of log (say, an audit log) would get a new option. This has more flexibility than specifying a directory which has to contain all of them. \* excluding `db.log` which is internally generated by the wallet database library, but that one moves along with `-walletdir`. Tree-SHA512: 4434d0e598dc23504e5c9e67fdbaef56db4f0fd490f9f54fd503e69d4dda9b5b69c539e1794ed841e72161b7b1dc3374d2f1193dd431b057566750e56fd8f24b