Squashed 'src/ipc/libmultiprocess/' changes from 47d79db8a552..ec86e4336e98

ec86e4336e98 Merge bitcoin-core/libmultiprocess#220: Add log levels and advertise them to users via logging callback
515ce93ad349 Logging: Pass LogData struct to logging callback
213574ccc43d Logging: reclassify remaining log messages
e4de0412b430 Logging: Break out expensive log messages and classify them as Trace
408874a78fdc Logging: Use new logging macros
67b092d835cd Logging: Disable logging if messsage level is less than the requested level
d0a1ba7ebf21 Logging: add log levels to mirror Core's
463a8296d188 Logging: Disable moving or copying Logger
83a2e10c0b03 Logging: Add an EventLoop constructor to allow for user-specified log options
58cf47a7fc8c Merge bitcoin-core/libmultiprocess#221: test default PassField impl handles output parameters
db03a663f514 Merge bitcoin-core/libmultiprocess#214: Fix crash on simultaneous IPC calls using the same thread
afcc40b0f1e8 Merge bitcoin-core/libmultiprocess#213: util+doc: Clearer errors when attempting to run examples + polished docs
6db669628387 test In|Out parameter
29cf2ada75ea test default PassField impl handles output parameters
1238170f68e8 test: simultaneous IPC calls using same thread
eb069ab75d83 Fix crash on simultaneous IPC calls using the same thread
ec03a9639ab5 doc: Precision and typos
2b4348193551 doc: Where possible, remove links to ryanofsky/bitcoin/
286fe469c9c9 util: Add helpful error message when failing to execute file

git-subtree-dir: src/ipc/libmultiprocess
git-subtree-split: ec86e4336e986a02b08ab12f7eea9f74551c5bef

Author: ryanofsky

doc/design.md

@@ -2,8 +2,8 @@
 
 Given an interface description of an object with one or more methods, libmultiprocess generates:
 
-* A C++ `ProxyClient` class with an implementation of each interface method that sends a request over a socket, waits for a response, and returns the result.
-* A C++ `ProxyServer` class that listens for requests over a socket and calls a wrapped C++ object implementing the same interface to actually execute the requests.
+* A C++ `ProxyClient` class template specialization with an implementation of each interface method that sends a request over a socket, waits for a response, and returns the result.
+* A C++ `ProxyServer` class template specialization that listens for requests over a socket and calls a wrapped C++ object implementing the same interface to actually execute the requests.
 
 The function call ⇆ request translation supports input and output arguments, standard types like `unique_ptr`, `vector`, `map`, and `optional`, and bidirectional calls between processes through interface pointer and `std::function` arguments.
 
@@ -15,21 +15,21 @@ Libmultiprocess acts as a pure wrapper or layer over the underlying protocol. Cl
 
 ### Internals
 
-The `ProxyClient` and `ProxyServer` generated classes are not directly exposed to the user, as described in [usage.md](usage.md). Instead, they wrap c++ interfaces and appear to the user as pointers to an interface. They are first instantiated when calling `ConnectStream` and `ServeStream` respectively for creating the `InitInterface`. These methods establish connections through sockets, internally creating `Connection` objects wrapping a `capnp::RpcSystem` configured for client and server mode respectively.
+The `ProxyClient` and `ProxyServer` generated classes are not directly exposed to the user, as described in [usage.md](usage.md). Instead, they wrap C++ interfaces and appear to the user as pointers to an interface. They are first instantiated when calling `ConnectStream` and `ServeStream` respectively for creating the `InitInterface`. These methods establish connections through sockets, internally creating `Connection` objects wrapping a `capnp::RpcSystem` configured for client and server mode respectively.
 
 The `InitInterface` interface will typically have methods which return other interfaces, giving the connecting process the ability to call other functions in the serving process. Interfaces can also have methods accepting other interfaces as parameters, giving serving processes the ability to call back and invoke functions in connecting processes. Creating new interfaces does not create new connections, and typically many interface objects will share the same connection.
 
 Both `ConnectStream` and `ServeStream` also require an instantiation of the `EventLoop`. The `EventLoop` owns pending requests, notifies on request dispatch, allows clients from multiple threads to make synchronous calls, and handles some cleanup routines on exit. It must be run in a separate thread so it is always active and can process incoming requests from local clients and remote connections.
 
 When a generated method on the `ProxyClient` is called, it calls `clientInvoke` with the capnp-translated types. `clientInvoke` creates a self-executing promise (`kj::TaskSet`) that drives the execution of the request and gives ownership of it to the `EventLoop`. `clientInvoke` blocks until a response is received, or until there is a call from the server that needs to run on the same client thread, using a `Waiter` object.
 
-On the server side, the `capnp::RpcSystem` receives the capnp request and invokes the corresponding c++ method through the corresponding `ProxyServer` and the heavily templated `serverInvoke` triggering a `ServerCall`. Its return values from the actual c++ methods are copied into capnp responses by `ServerRet` and exceptions are caught and copied by `ServerExcept`. The two are connected through `ServerField`. The main method driving execution of a request is `PassField`, which is invoked through `ServerField`. Instantiated interfaces, or capabilities in capnp speak, are tracked and owned by the server's `capnp::RpcSystem`.
+On the server side, the `capnp::RpcSystem` receives the capnp request and invokes the corresponding C++ method through the corresponding `ProxyServer` and the heavily templated `serverInvoke` triggering a `ServerCall`. The return values from the actual C++ methods are copied into capnp responses by `ServerRet` and exceptions are caught and copied by `ServerExcept`. The two are connected through `ServerField`. The main method driving execution of a request is `PassField`, which is invoked through `ServerField`. Instantiated interfaces, or capabilities in capnp speak, are tracked and owned by the server's `capnp::RpcSystem`.
 
 ## Interface descriptions
 
 As explained in the [usage](usage.md) document, interface descriptions need to be consumed both by the _libmultiprocess_ code generator, and by C++ code that calls and implements the interfaces. The C++ code only needs to know about C++ arguments and return types, while the code generator only needs to know about capnp arguments and return types, but both need to know class and method names, so the corresponding `.h` and `.capnp` source files contain some of the same information, and have to be kept in sync manually when methods or parameters change. Despite the redundancy, reconciling the interface definitions is designed to be _straightforward_ and _safe_. _Straightforward_ because there is no need to write manual serialization code or use awkward intermediate types like [`UniValue`](https://github.com/bitcoin/bitcoin/blob/master/src/univalue/include/univalue.h) instead of native types. _Safe_ because if there are any inconsistencies between API and data definitions (even minor ones like using a narrow int data type for a wider int API input), there are errors at build time instead of errors or bugs at runtime.
 
-In the future, it would be possible to combine API and data definitions together using [C++ attributes](https://en.cppreference.com/w/cpp/language/attributes). To do this we would add attributes to the API definition files, and then generate the data definitions from the API definitions and attributes. I didn't take this approach mostly because it would be extra work, but also because until c++ standardizes reflection, this would require either hooking into compiler APIs like https://github.com/RosettaCommons/binder, or parsing c++ code manually like http://www.swig.org/.
+In the future, it would be possible to combine API and data definitions together using [C++ attributes](https://en.cppreference.com/w/cpp/language/attributes). To do this we would add attributes to the API definition files, and then generate the data definitions from the API definitions and attributes. I didn't take this approach mostly because it would be extra work, but also because until C++ standardizes reflection, this would require either hooking into compiler APIs like https://github.com/RosettaCommons/binder, or parsing C++ code manually like http://www.swig.org/.
 
 ## What is `kj`?
 
@@ -39,6 +39,6 @@ basis in this library to construct the event-loop necessary to service IPC reque
 
 ## Future directions
 
-_libmultiprocess_ uses the [Cap'n Proto](https://capnproto.org) interface description language and protocol, but it could be extended or changed to use a different IDL/protocol like [gRPC](https://grpc.io). The nice thing about _Cap'n Proto_ compared to _gRPC_ and most other lower level protocols is that it allows interface pointers (_Services_ in gRPC parlance) to be passed as method arguments and return values, so object references and bidirectional requests work out of the box. Supporting a lower-level protocol would require writing adding maps and tracking code to proxy objects.
+_libmultiprocess_ uses the [Cap'n Proto](https://capnproto.org) interface description language and protocol, but it could be extended or changed to use a different IDL/protocol like [gRPC](https://grpc.io). The nice thing about _Cap'n Proto_ compared to _gRPC_ and most other lower level protocols is that it allows interface pointers (_Services_ in gRPC parlance) to be passed as method arguments and return values, so object references and bidirectional requests work out of the box. Supporting a lower-level protocol would require adding maps and tracking code to proxy objects.
 
 _libmultiprocess_ is currently compatible with sandboxing but could add platform-specific sandboxing support or integration with a sandboxing library like [SAPI](https://github.com/google/sandboxed-api).

doc/usage.md

@@ -4,9 +4,9 @@
 
 _libmultiprocess_ is a library and code generator that allows calling C++ class interfaces across different processes. For an interface to be available from other processes, it needs two definitions:
 
-- An **API definition** declaring how the interface is called. Included examples: [calculator.h](https://github.com/bitcoin-core/libmultiprocess/blob/master/example/calculator.h), [printer.h](https://github.com/bitcoin-core/libmultiprocess/blob/master/example/printer.h), [init.h](https://github.com/bitcoin-core/libmultiprocess/blob/master/example/init.h). Bitcoin examples: [node.h](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/interfaces/node.h), [wallet.h](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/interfaces/wallet.h), [echo.h](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/interfaces/echo.h), [init.h](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/interfaces/init.h).
+- An **API definition** declaring how the interface is called. Included examples: [calculator.h](../example/calculator.h), [printer.h](../example/printer.h), [init.h](../example/init.h). Bitcoin examples: [node.h](https://github.com/bitcoin/bitcoin/blob/master/src/interfaces/node.h), [wallet.h](https://github.com/bitcoin/bitcoin/blob/master/src/interfaces/wallet.h), [echo.h](https://github.com/bitcoin/bitcoin/blob/master/src/interfaces/echo.h), [init.h](https://github.com/bitcoin/bitcoin/blob/master/src/interfaces/init.h).
 
-- A **data definition** declaring how interface calls get sent across the wire. Included examples: [calculator.capnp](https://github.com/bitcoin-core/libmultiprocess/blob/master/example/calculator.capnp), [printer.capnp](https://github.com/bitcoin-core/libmultiprocess/blob/master/example/printer.capnp), [init.capnp](https://github.com/bitcoin-core/libmultiprocess/blob/master/example/init.capnp). Bitcoin examples: [node.capnp](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/ipc/capnp/node.capnp), [wallet.capnp](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/ipc/capnp/wallet.capnp), [echo.capnp](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/ipc/capnp/echo.capnp), [init.capnp](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/ipc/capnp/init.capnp).
+- A **data definition** declaring how interface calls get sent across the wire. Included examples: [calculator.capnp](../example/calculator.capnp), [printer.capnp](../example/printer.capnp), [init.capnp](../example/init.capnp). Bitcoin examples: [node.capnp](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/ipc/capnp/node.capnp), [wallet.capnp](https://github.com/ryanofsky/bitcoin/blob/ipc-export/src/ipc/capnp/wallet.capnp), [echo.capnp](https://github.com/bitcoin/bitcoin/blob/master/src/ipc/capnp/echo.capnp), [init.capnp](https://github.com/bitcoin/bitcoin/blob/master/src/ipc/capnp/init.capnp).
 
 The `*.capnp` data definition files are consumed by the _libmultiprocess_ code generator and each `X.capnp` file generates `X.capnp.c++`, `X.capnp.h`, `X.capnp.proxy-client.c++`, `X.capnp.proxy-server.c++`, `X.capnp.proxy-types.c++`, `X.capnp.proxy-types.h`, and `X.capnp.proxy.h` output files. The generated files include `mp::ProxyClient<Interface>` and `mp::ProxyServer<Interface>` class specializations for all the interfaces in the `.capnp` files. These allow methods on C++ objects in one process to be called from other processes over IPC sockets.
 

example/calculator.cpp

@@ -9,6 +9,7 @@
 #include <charconv>
 #include <cstring>
 #include <fstream>
+#include <functional>
 #include <iostream>
 #include <kj/async.h>
 #include <kj/common.h>
@@ -37,6 +38,7 @@ class InitImpl : public Init
     }
 };
 
+// Exercises deprecated log callback signature
 static void LogPrint(bool raise, const std::string& message)
 {
     if (raise) throw std::runtime_error(message);

example/example.cpp

@@ -35,10 +35,10 @@ static auto Spawn(mp::EventLoop& loop, const std::string& process_argv0, const s
     return std::make_tuple(mp::ConnectStream<InitInterface>(loop, fd), pid);
 }
 
-static void LogPrint(bool raise, const std::string& message)
+static void LogPrint(mp::LogMessage log_data)
 {
-    if (raise) throw std::runtime_error(message);
-    std::ofstream("debug.log", std::ios_base::app) << message << std::endl;
+    if (log_data.level == mp::Log::Raise) throw std::runtime_error(log_data.message);
+    std::ofstream("debug.log", std::ios_base::app) << log_data.message << std::endl;
 }
 
 int main(int argc, char** argv)

example/printer.cpp

@@ -32,10 +32,10 @@ class InitImpl : public Init
     std::unique_ptr<Printer> makePrinter() override { return std::make_unique<PrinterImpl>(); }
 };
 
-static void LogPrint(bool raise, const std::string& message)
+static void LogPrint(mp::LogMessage log_data)
 {
-    if (raise) throw std::runtime_error(message);
-    std::ofstream("debug.log", std::ios_base::app) << message << std::endl;
+    if (log_data.level == mp::Log::Raise) throw std::runtime_error(log_data.message);
+    std::ofstream("debug.log", std::ios_base::app) << log_data.message << std::endl;
 }
 
 int main(int argc, char** argv)

include/mp/proxy-io.h

@@ -98,22 +98,59 @@ class LoggingErrorHandler : public kj::TaskSet::ErrorHandler
     EventLoop& m_loop;
 };
 
-using LogFn = std::function<void(bool raise, std::string message)>;
+enum class Log {
+    Trace = 0,
+    Debug,
+    Info,
+    Warning,
+    Error,
+    Raise,
+};
+
+struct LogMessage {
+
+    //! Message to be logged
+    std::string message;
+
+    //! The severity level of this message
+    Log level;
+};
+
+using LogFn = std::function<void(LogMessage)>;
+
+struct LogOptions {
+
+    //! External logging callback.
+    LogFn log_fn;
+
+    //! Maximum number of characters to use when representing
+    //! request and response structs as strings.
+    size_t max_chars{200};
+
+    //! Messages with a severity level less than log_level will not be
+    //! reported.
+    Log log_level{Log::Trace};
+};
 
 class Logger
 {
 public:
-    Logger(bool raise, LogFn& fn) : m_raise(raise), m_fn(fn) {}
-    Logger(Logger&& logger) : m_raise(logger.m_raise), m_fn(logger.m_fn), m_buffer(std::move(logger.m_buffer)) {}
+    Logger(const LogOptions& options, Log log_level) : m_options(options), m_log_level(log_level) {}
+
+    Logger(Logger&&) = delete;
+    Logger& operator=(Logger&&) = delete;
+    Logger(const Logger&) = delete;
+    Logger& operator=(const Logger&) = delete;
+
     ~Logger() noexcept(false)
     {
-        if (m_fn) m_fn(m_raise, m_buffer.str());
+        if (enabled()) m_options.log_fn({std::move(m_buffer).str(), m_log_level});
     }
 
     template <typename T>
     friend Logger& operator<<(Logger& logger, T&& value)
     {
-        if (logger.m_fn) logger.m_buffer << std::forward<T>(value);
+        if (logger.enabled()) logger.m_buffer << std::forward<T>(value);
         return logger;
     }
 
@@ -123,20 +160,25 @@ class Logger
         return logger << std::forward<T>(value);
     }
 
-    bool m_raise;
-    LogFn& m_fn;
+    explicit operator bool() const
+    {
+        return enabled();
+    }
+
+private:
+    bool enabled() const
+    {
+        return m_options.log_fn && m_log_level >= m_options.log_level;
+    }
+
+    const LogOptions& m_options;
+    Log m_log_level;
     std::ostringstream m_buffer;
 };
 
-struct LogOptions {
+#define MP_LOGPLAIN(loop, ...) if (mp::Logger logger{(loop).m_log_opts, __VA_ARGS__}; logger) logger
 
-    //! External logging callback.
-    LogFn log_fn;
-
-    //! Maximum number of characters to use when representing
-    //! request and response structs as strings.
-    size_t max_chars{200};
-};
+#define MP_LOG(loop, ...) MP_LOGPLAIN(loop, __VA_ARGS__) << "{" << LongThreadName((loop).m_exe_name) << "} "
 
 std::string LongThreadName(const char* exe_name);
 
@@ -168,8 +210,19 @@ std::string LongThreadName(const char* exe_name);
 class EventLoop
 {
 public:
-    //! Construct event loop object.
-    EventLoop(const char* exe_name, LogFn log_fn, void* context = nullptr);
+    //! Construct event loop object with default logging options.
+    EventLoop(const char* exe_name, LogFn log_fn, void* context = nullptr)
+        : EventLoop(exe_name, LogOptions{std::move(log_fn)}, context){}
+
+    //! Construct event loop object with specified logging options.
+    EventLoop(const char* exe_name, LogOptions log_opts, void* context = nullptr);
+
+    //! Backwards-compatible constructor for previous (deprecated) logging callback signature
+    EventLoop(const char* exe_name, std::function<void(bool, std::string)> old_callback, void* context = nullptr)
+        : EventLoop(exe_name,
+                LogFn{[old_callback = std::move(old_callback)](LogMessage log_data) {old_callback(log_data.level == Log::Raise, std::move(log_data.message));}},
+                context){}
+
     ~EventLoop();
 
     //! Run event loop. Does not return until shutdown. This should only be
@@ -210,15 +263,6 @@ class EventLoop
     //! Check if loop should exit.
     bool done() const MP_REQUIRES(m_mutex);
 
-    Logger log()
-    {
-        Logger logger(false, m_log_opts.log_fn);
-        logger << "{" << LongThreadName(m_exe_name) << "} ";
-        return logger;
-    }
-    Logger logPlain() { return {false, m_log_opts.log_fn}; }
-    Logger raise() { return {true, m_log_opts.log_fn}; }
-
     //! Process name included in thread names so combined debug output from
     //! multiple processes is easier to understand.
     const char* m_exe_name;
@@ -281,12 +325,13 @@ struct Waiter
     Waiter() = default;
 
     template <typename Fn>
-    void post(Fn&& fn)
+    bool post(Fn&& fn)
     {
         const Lock lock(m_mutex);
-        assert(!m_fn);
+        if (m_fn) return false;
         m_fn = std::forward<Fn>(fn);
         m_cv.notify_all();
+        return true;
     }
 
     template <class Predicate>
@@ -642,7 +687,7 @@ std::unique_ptr<ProxyClient<InitInterface>> ConnectStream(EventLoop& loop, int f
         init_client = connection->m_rpc_system->bootstrap(ServerVatId().vat_id).castAs<InitInterface>();
         Connection* connection_ptr = connection.get();
         connection->onDisconnect([&loop, connection_ptr] {
-            loop.log() << "IPC client: unexpected network disconnect.";
+            MP_LOG(loop, Log::Warning) << "IPC client: unexpected network disconnect.";
             delete connection_ptr;
         });
     });
@@ -665,7 +710,7 @@ void _Serve(EventLoop& loop, kj::Own<kj::AsyncIoStream>&& stream, InitImpl& init
     });
     auto it = loop.m_incoming_connections.begin();
     it->onDisconnect([&loop, it] {
-        loop.log() << "IPC server: socket disconnected.";
+        MP_LOG(loop, Log::Info) << "IPC server: socket disconnected.";
         loop.m_incoming_connections.erase(it);
     });
 }