multiprocess: Add debug.log .wallet/.gui suffixes

Add .wallet/.gui suffixes to log files created by bitcoin-gui and
bitcoin-wallet processes so they don't clash with bitcoin-node log file.

src/bitcoind.cpp

@@ -14,6 +14,7 @@
 #include <init.h>
 #include <interfaces/chain.h>
 #include <interfaces/init.h>
+#include <interfaces/ipc.h>
 #include <kernel/context.h>
 #include <node/context.h>
 #include <node/interface_ui.h>
@@ -172,7 +173,8 @@ static bool AppInit(NodeContext& node)
         // -server defaults to true for bitcoind but not for the GUI so do this here
         args.SoftSetBoolArg("-server", true);
         // Set this early so that parameter interactions go to console
-        InitLogging(args);
+        interfaces::Ipc* ipc = node.init->ipc();
+        InitLogging(args, ipc ? ipc->logSuffix() : nullptr);
         InitParameterInteraction(args);
         if (!AppInitBasicSetup(args, node.exit_status)) {
             // InitError will have been called with detailed error, which ends up on console

src/init.cpp

@@ -830,9 +830,9 @@ void InitParameterInteraction(ArgsManager& args)
  * Note that this is called very early in the process lifetime, so you should be
  * careful about what global state you rely on here.
  */
-void InitLogging(const ArgsManager& args)
+void InitLogging(const ArgsManager& args, const char* log_suffix)
 {
-    init::SetLoggingOptions(args);
+    init::SetLoggingOptions(args, log_suffix);
     init::LogPackageVersion();
 }
 

src/init.h

@@ -33,7 +33,7 @@ bool ShutdownRequested(node::NodeContext& node);
 void Interrupt(node::NodeContext& node);
 void Shutdown(node::NodeContext& node);
 //!Initialize the logging infrastructure
-void InitLogging(const ArgsManager& args);
+void InitLogging(const ArgsManager& args, const char* log_suffix);
 //!Parameter interaction: change current parameters depending on various rules
 void InitParameterInteraction(ArgsManager& args);
 

src/init/bitcoin-gui.cpp

@@ -22,7 +22,7 @@ const char* EXE_NAME = "bitcoin-gui";
 class BitcoinGuiInit : public interfaces::Init
 {
 public:
-    BitcoinGuiInit(const char* arg0) : m_ipc(interfaces::MakeIpc(EXE_NAME, arg0, *this))
+    BitcoinGuiInit(const char* arg0) : m_ipc(interfaces::MakeIpc(EXE_NAME, ".gui", arg0, *this))
     {
         ipc::capnp::SetupNodeClient(m_ipc->context());
     }

src/init/bitcoin-node.cpp

@@ -34,16 +34,15 @@ class BitcoinNodeInit : public interfaces::Init
 {
 public:
     BitcoinNodeInit(node::NodeContext& node, const char* arg0)
-        : m_node(node),
-          m_ipc(interfaces::MakeIpc(EXE_NAME, arg0, *this))
+        : m_node(node), m_ipc(interfaces::MakeIpc(EXE_NAME, "", arg0, *this))
     {
         InitContext(m_node);
         m_node.init = this;
         // Extra initialization code that runs when a bitcoin-node process is
         // spawned by a bitcoin-gui process, after the ArgsManager configuration
         // is transferred from the parent process to the child process.
         m_ipc->context().init_process = [this] {
-            InitLogging(*Assert(m_node.args));
+            InitLogging(*Assert(m_node.args), m_ipc->logSuffix());
             InitParameterInteraction(*Assert(m_node.args));
         };
         ipc::capnp::SetupNodeServer(m_ipc->context());

src/init/bitcoin-wallet-ipc.cpp

@@ -42,7 +42,7 @@ const char* EXE_NAME = "bitcoin-wallet";
 class BitcoinWalletInit : public interfaces::Init
 {
 public:
-    BitcoinWalletInit(const char* arg0) : m_ipc(interfaces::MakeIpc(EXE_NAME, arg0, *this))
+    BitcoinWalletInit(const char* arg0) : m_ipc(interfaces::MakeIpc(EXE_NAME, ".wallet", arg0, *this))
     {
         // Extra initialization code that runs when a bitcoin-wallet process is
         // spawned by a bitcoin-node process, after the ArgsManager
@@ -58,7 +58,7 @@ class BitcoinWalletInit : public interfaces::Init
             // util::Globals class that becomes a memberof kernel::Context
             m_kernel.emplace();
             m_ecc_context.emplace();
-            init::SetLoggingOptions(gArgs);
+            init::SetLoggingOptions(gArgs, m_ipc->logSuffix());
             if (auto result = init::SetLoggingCategories(gArgs); !result) {
                 throw std::runtime_error(util::ErrorString(result).original);
             }

src/init/common.cpp

@@ -41,10 +41,11 @@ void AddLoggingArgs(ArgsManager& argsman)
     argsman.AddArg("-shrinkdebugfile", "Shrink debug.log file on client startup (default: 1 when no -debug)", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
 }
 
-void SetLoggingOptions(const ArgsManager& args)
+void SetLoggingOptions(const ArgsManager& args, const char* log_suffix)
 {
     LogInstance().m_print_to_file = !args.IsArgNegated("-debuglogfile");
     LogInstance().m_file_path = AbsPathForConfigVal(args, args.GetPathArg("-debuglogfile", DEFAULT_DEBUGLOGFILE));
+    if (log_suffix && LogInstance().m_file_path != "/dev/null") LogInstance().m_file_path += log_suffix;
     LogInstance().m_print_to_console = args.GetBoolArg("-printtoconsole", !args.GetBoolArg("-daemon", false));
     LogInstance().m_log_timestamps = args.GetBoolArg("-logtimestamps", DEFAULT_LOGTIMESTAMPS);
     LogInstance().m_log_time_micros = args.GetBoolArg("-logtimemicros", DEFAULT_LOGTIMEMICROS);

src/init/common.h

@@ -14,7 +14,7 @@ class ArgsManager;
 
 namespace init {
 void AddLoggingArgs(ArgsManager& args);
-void SetLoggingOptions(const ArgsManager& args);
+void SetLoggingOptions(const ArgsManager& args, const char* log_suffix);
 [[nodiscard]] util::Result<void> SetLoggingCategories(const ArgsManager& args);
 [[nodiscard]] util::Result<void> SetLoggingLevel(const ArgsManager& args);
 bool StartLogging(const ArgsManager& args);

src/interfaces/ipc.h

@@ -81,14 +81,17 @@ class Ipc
     //! IPC context struct accessor (see struct definition for more description).
     virtual ipc::Context& context() = 0;
 
+    //! Suffix for debug.log to avoid output clashes from different processes.
+    virtual const char* logSuffix() = 0;
+
 protected:
     //! Internal implementation of public addCleanup method (above) as a
     //! type-erased virtual function, since template functions can't be virtual.
     virtual void addCleanup(std::type_index type, void* iface, std::function<void()> cleanup) = 0;
 };
 
 //! Return implementation of Ipc interface.
-std::unique_ptr<Ipc> MakeIpc(const char* exe_name, const char* process_argv0, Init& init);
+std::unique_ptr<Ipc> MakeIpc(const char* exe_name, const char* log_suffix, const char* process_argv0, Init& init);
 } // namespace interfaces
 
 #endif // BITCOIN_INTERFACES_IPC_H

src/ipc/interfaces.cpp

@@ -29,8 +29,8 @@ namespace {
 class IpcImpl : public interfaces::Ipc
 {
 public:
-    IpcImpl(const char* exe_name, const char* process_argv0, interfaces::Init& init)
-        : m_exe_name(exe_name), m_process_argv0(process_argv0), m_init(init),
+    IpcImpl(const char* exe_name, const char* log_suffix, const char* process_argv0, interfaces::Init& init)
+        : m_exe_name(exe_name), m_log_suffix(log_suffix), m_process_argv0(process_argv0), m_init(init),
           m_protocol(ipc::capnp::MakeCapnpProtocol()), m_process(ipc::MakeProcess())
     {
     }
@@ -91,7 +91,9 @@ class IpcImpl : public interfaces::Ipc
         m_protocol->addCleanup(type, iface, std::move(cleanup));
     }
     Context& context() override { return m_protocol->context(); }
+    const char* logSuffix() override { return m_log_suffix; }
     const char* m_exe_name;
+    const char* m_log_suffix;
     const char* m_process_argv0;
     interfaces::Init& m_init;
     std::unique_ptr<Protocol> m_protocol;
@@ -101,8 +103,8 @@ class IpcImpl : public interfaces::Ipc
 } // namespace ipc
 
 namespace interfaces {
-std::unique_ptr<Ipc> MakeIpc(const char* exe_name, const char* process_argv0, Init& init)
+std::unique_ptr<Ipc> MakeIpc(const char* exe_name, const char* log_suffix, const char* process_argv0, Init& init)
 {
-    return std::make_unique<ipc::IpcImpl>(exe_name, process_argv0, init);
+    return std::make_unique<ipc::IpcImpl>(exe_name, log_suffix, process_argv0, init);
 }
 } // namespace interfaces

src/node/interfaces.cpp

@@ -15,6 +15,8 @@
 #include <init.h>
 #include <interfaces/chain.h>
 #include <interfaces/handler.h>
+#include <interfaces/init.h>
+#include <interfaces/ipc.h>
 #include <interfaces/mining.h>
 #include <interfaces/node.h>
 #include <interfaces/wallet.h>
@@ -97,7 +99,11 @@ class NodeImpl : public Node
 {
 public:
     explicit NodeImpl(NodeContext& context) { setContext(&context); }
-    void initLogging() override { InitLogging(args()); }
+    void initLogging() override
+    {
+        interfaces::Ipc* ipc = m_context->init->ipc();
+        InitLogging(args(), ipc ? ipc->logSuffix() : nullptr);
+    }
     void initParameterInteraction() override { InitParameterInteraction(args()); }
     bilingual_str getWarnings() override { return Join(Assert(m_context->warnings)->GetMessages(), Untranslated("<hr />")); }
     int getExitStatus() override { return Assert(m_context)->exit_status.load(); }

src/qt/bitcoin.cpp

@@ -327,13 +327,14 @@ void BitcoinApplication::startThread()
     connect(this, &BitcoinApplication::requestedShutdown, &m_executor.value(), &InitExecutor::shutdown);
 }
 
-void BitcoinApplication::parameterSetup()
+void BitcoinApplication::parameterSetup(interfaces::Init& init)
 {
     // Default printtoconsole to false for the GUI. GUI programs should not
     // print to the console unnecessarily.
     gArgs.SoftSetBoolArg("-printtoconsole", false);
 
-    InitLogging(gArgs);
+    interfaces::Ipc* ipc = init.ipc();
+    InitLogging(gArgs, ipc ? ipc->logSuffix() : nullptr);
     InitParameterInteraction(gArgs);
 }
 
@@ -673,7 +674,7 @@ int GuiMain(int argc, char* argv[])
     // Install qDebug() message handler to route to debug.log
     qInstallMessageHandler(DebugMessageHandler);
     // Allow parameter interaction before we create the options model
-    app.parameterSetup();
+    app.parameterSetup(*init);
     GUIUtil::LogQtInfo();
 
     if (gArgs.GetBoolArg("-splash", DEFAULT_SPLASHSCREEN) && !gArgs.GetBoolArg("-min", false))

src/qt/bitcoin.h

@@ -43,7 +43,7 @@ class BitcoinApplication: public QApplication
     void createPaymentServer();
 #endif
     /// parameter interaction/setup based on rules
-    void parameterSetup();
+    void parameterSetup(interfaces::Init& init);
     /// Create options model
     [[nodiscard]] bool createOptionsModel(bool resetSettings);
     /// Initialize prune setting

src/qt/test/apptests.cpp

@@ -52,7 +52,7 @@ void TestRpcCommand(RPCConsole* console)
 } // namespace
 
 //! Entry point for BitcoinApplication tests.
-void AppTests::appTests()
+void AppTests::appTests(interfaces::Init& init)
 {
 #ifdef Q_OS_MACOS
     if (QApplication::platformName() == "minimal") {
@@ -67,7 +67,7 @@ void AppTests::appTests()
 #endif
 
     qRegisterMetaType<interfaces::BlockAndHeaderTipInfo>("interfaces::BlockAndHeaderTipInfo");
-    m_app.parameterSetup();
+    m_app.parameterSetup(init);
     QVERIFY(m_app.createOptionsModel(/*resetSettings=*/true));
     QScopedPointer<const NetworkStyle> style(NetworkStyle::instantiate(Params().GetChainType()));
     m_app.setupPlatformStyle();

src/qt/test/apptests.h

@@ -14,14 +14,18 @@ class BitcoinApplication;
 class BitcoinGUI;
 class RPCConsole;
 
+namespace interfaces {
+class Init;
+} // namespace interfaces
+
 class AppTests : public QObject
 {
     Q_OBJECT
 public:
     explicit AppTests(BitcoinApplication& app) : m_app(app) {}
 
 private Q_SLOTS:
-    void appTests();
+    void appTests(interfaces::Init& init);
     void guiTests(BitcoinGUI* window);
     void consoleTests(RPCConsole* console);
 

src/test/util/setup_common.cpp

@@ -172,7 +172,7 @@ BasicTestingSetup::BasicTestingSetup(const ChainType chainType, TestOpts opts)
 
     SelectParams(chainType);
     if (G_TEST_LOG_FUN) LogInstance().PushBackCallback(G_TEST_LOG_FUN);
-    InitLogging(*m_node.args);
+    InitLogging(*m_node.args, /* log_suffix= */ nullptr);
     AppInitParameterInteraction(*m_node.args);
     LogInstance().StartLogging();
     m_node.warnings = std::make_unique<node::Warnings>();

test/functional/combine_logs.py

@@ -95,6 +95,10 @@ def read_logs(tmp_dir):
             break
         files.append(("node%d" % i, logfile))
 
+        wallet_logfile = "{}/node{}/regtest/debug.log.wallet".format(tmp_dir, i)
+        if os.path.isfile(wallet_logfile):
+            files.append(("wall%d" % i, wallet_logfile))
+
     return heapq.merge(*[get_log_events(source, f) for source, f in files])
 
 

test/functional/feature_posix_fs_permissions.py

@@ -35,7 +35,7 @@ def run_test(self):
         self.check_directory_permissions(datadir)
         walletsdir = self.nodes[0].wallets_path
         self.check_directory_permissions(walletsdir)
-        debuglog = self.nodes[0].debug_log_path
+        debuglog = self.nodes[0].debug_log_path(wallet=False)
         self.check_file_permissions(debuglog)
 
 

test/functional/test_framework/test_node.py

@@ -463,9 +463,13 @@ def replace_in_config(self, replacements):
     def chain_path(self) -> Path:
         return self.datadir_path / self.chain
 
-    @property
-    def debug_log_path(self) -> Path:
-        return self.chain_path / 'debug.log'
+    def debug_log_path(self, wallet: bool) -> Path:
+        path = self.chain_path / 'debug.log'
+        if wallet:
+            wallet_path = path.with_name(path.name + ".wallet")
+            if wallet_path.exists():
+                path = wallet_path
+        return path
 
     @property
     def blocks_path(self) -> Path:
@@ -483,26 +487,26 @@ def read_xor_key(self) -> bytes:
     def wallets_path(self) -> Path:
         return self.chain_path / "wallets"
 
-    def debug_log_size(self, **kwargs) -> int:
-        with open(self.debug_log_path, **kwargs) as dl:
+    def debug_log_size(self, wallet: bool, **kwargs) -> int:
+        with open(self.debug_log_path(wallet), **kwargs) as dl:
             dl.seek(0, 2)
             return dl.tell()
 
     @contextlib.contextmanager
-    def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2):
+    def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2, wallet=False):
         if unexpected_msgs is None:
             unexpected_msgs = []
         assert_equal(type(expected_msgs), list)
         assert_equal(type(unexpected_msgs), list)
 
         time_end = time.time() + timeout * self.timeout_factor
-        prev_size = self.debug_log_size(encoding="utf-8")  # Must use same encoding that is used to read() below
+        prev_size = self.debug_log_size(wallet, encoding="utf-8")  # Must use same encoding that is used to read() below
 
         yield
 
         while True:
             found = True
-            with open(self.debug_log_path, encoding="utf-8", errors="replace") as dl:
+            with open(self.debug_log_path(wallet), encoding="utf-8", errors="replace") as dl:
                 dl.seek(prev_size)
                 log = dl.read()
             print_log = " - " + "\n - ".join(log.splitlines())
@@ -520,20 +524,20 @@ def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2):
         self._raise_assertion_error('Expected messages "{}" does not partially match log:\n\n{}\n\n'.format(str(expected_msgs), print_log))
 
     @contextlib.contextmanager
-    def busy_wait_for_debug_log(self, expected_msgs, timeout=60):
+    def busy_wait_for_debug_log(self, expected_msgs, timeout=60, wallet=False):
         """
         Block until we see a particular debug log message fragment or until we exceed the timeout.
         Return:
             the number of log lines we encountered when matching
         """
         time_end = time.time() + timeout * self.timeout_factor
-        prev_size = self.debug_log_size(mode="rb")  # Must use same mode that is used to read() below
+        prev_size = self.debug_log_size(wallet, mode="rb")  # Must use same mode that is used to read() below
 
         yield
 
         while True:
             found = True
-            with open(self.debug_log_path, "rb") as dl:
+            with open(self.debug_log_path(wallet), "rb") as dl:
                 dl.seek(prev_size)
                 log = dl.read()
 

test/functional/wallet_dump.py

@@ -209,7 +209,7 @@ def run_test(self):
         assert result['ismine']
 
         self.log.info('Check that wallet is flushed')
-        with self.nodes[0].assert_debug_log(['Flushing wallet.dat'], timeout=20):
+        with self.nodes[0].assert_debug_log(['Flushing wallet.dat'], timeout=20, wallet=True):
             self.nodes[0].getnewaddress()
 
         # Make sure that dumpwallet doesn't have a lock order issue when there is an unconfirmed tx and it is reloaded

test/functional/wallet_fast_rescan.py

@@ -65,26 +65,26 @@ def run_test(self):
             self.generate(node, 1)
 
         self.log.info("Import wallet backup with block filter index")
-        with node.assert_debug_log(['fast variant using block filters']):
+        with node.assert_debug_log(['fast variant using block filters'], wallet=True):
             node.restorewallet('rescan_fast', WALLET_BACKUP_FILENAME)
         txids_fast = self.get_wallet_txids(node, 'rescan_fast')
 
         self.log.info("Import non-active descriptors with block filter index")
         node.createwallet(wallet_name='rescan_fast_nonactive', descriptors=True, disable_private_keys=True, blank=True)
-        with node.assert_debug_log(['fast variant using block filters']):
+        with node.assert_debug_log(['fast variant using block filters'], wallet=True):
             w = node.get_wallet_rpc('rescan_fast_nonactive')
             w.importdescriptors([{"desc": descriptor['desc'], "timestamp": 0} for descriptor in descriptors])
         txids_fast_nonactive = self.get_wallet_txids(node, 'rescan_fast_nonactive')
 
         self.restart_node(0, [f'-keypool={KEYPOOL_SIZE}', '-blockfilterindex=0'])
         self.log.info("Import wallet backup w/o block filter index")
-        with node.assert_debug_log(['slow variant inspecting all blocks']):
+        with node.assert_debug_log(['slow variant inspecting all blocks'], wallet=True):
             node.restorewallet("rescan_slow", WALLET_BACKUP_FILENAME)
         txids_slow = self.get_wallet_txids(node, 'rescan_slow')
 
         self.log.info("Import non-active descriptors w/o block filter index")
         node.createwallet(wallet_name='rescan_slow_nonactive', descriptors=True, disable_private_keys=True, blank=True)
-        with node.assert_debug_log(['slow variant inspecting all blocks']):
+        with node.assert_debug_log(['slow variant inspecting all blocks'], wallet=True):
             w = node.get_wallet_rpc('rescan_slow_nonactive')
             w.importdescriptors([{"desc": descriptor['desc'], "timestamp": 0} for descriptor in descriptors])
         txids_slow_nonactive = self.get_wallet_txids(node, 'rescan_slow_nonactive')