test: Use KJ_LOG instead of std::cout for logging

This avoids thread sanitizer errors like:

  Read of size 8 at 0x7ffff7c81cb8 by thread T8:
    #0 std::__1::ios_base::width[abi:ne210101]() const /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/ios:497 (mptest+0x13e737)
    bitcoin-core#1 std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output[abi:ne210101]<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char) /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/__locale_dir/pad_and_output.h:54 (mptest+0x13e737)
    bitcoin-core#2 std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::__put_character_sequence[abi:ne210101]<char, std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*, unsigned long) /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/__ostream/put_character_sequence.h:37 (mptest+0x13e5e0)
    bitcoin-core#3 std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::operator<<[abi:ne210101]<std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*) /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/__ostream/basic_ostream.h:438 (mptest+0x13e0ee)

  Previous write of size 8 at 0x7ffff7c81cb8 by main thread (mutexes: write M0):
    #0 std::__1::ios_base::width[abi:ne210101](long) /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/ios:501 (mptest+0x13e8bc)
    bitcoin-core#1 std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output[abi:ne210101]<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char) /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/__locale_dir/pad_and_output.h:80 (mptest+0x13e8bc)
    bitcoin-core#2 std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::__put_character_sequence[abi:ne210101]<char, std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*, unsigned long) /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/__ostream/put_character_sequence.h:37 (mptest+0x13e5e0)
    bitcoin-core#3 std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::operator<<[abi:ne210101]<std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*) /nix/store/71bq4557fksv43c9lf9j5ywrj6zk17hl-libcxx-21.1.1-dev/include/c++/v1/__ostream/basic_ostream.h:438 (mptest+0x13e0ee)
    bitcoin-core#4 mp::test::TestSetup::TestSetup(bool)::{lambda()bitcoin-core#1}::operator()() const::{lambda(mp::LogMessage)bitcoin-core#1}::operator()(mp::LogMessage) const test/mp/test/test.cpp:71 (mptest+0x13e0ee)

Author: ryanofsky

include/mp/proxy-io.h

@@ -98,6 +98,7 @@ class LoggingErrorHandler : public kj::TaskSet::ErrorHandler
     EventLoop& m_loop;
 };
 
+//! Log flags. Update stringify function if changed!
 enum class Log {
     Trace = 0,
     Debug,
@@ -107,6 +108,8 @@ enum class Log {
     Raise,
 };
 
+kj::StringPtr KJ_STRINGIFY(Log flags);
+
 struct LogMessage {
 
     //! Message to be logged

src/mp/proxy.cpp

@@ -24,6 +24,7 @@
 #include <kj/debug.h>
 #include <kj/function.h>
 #include <kj/memory.h>
+#include <kj/string.h>
 #include <map>
 #include <memory>
 #include <optional>
@@ -430,4 +431,16 @@ std::string LongThreadName(const char* exe_name)
     return g_thread_context.thread_name.empty() ? ThreadName(exe_name) : g_thread_context.thread_name;
 }
 
+kj::StringPtr KJ_STRINGIFY(Log v)
+{
+    switch (v) {
+        case Log::Trace:   return "Trace";
+        case Log::Debug:   return "Debug";
+        case Log::Info:    return "Info";
+        case Log::Warning: return "Warning";
+        case Log::Error:   return "Error";
+        case Log::Raise:   return "Raise";
+    }
+    return "<Log?>";
+}
 } // namespace mp

test/mp/test/test.cpp

@@ -13,7 +13,6 @@
 #include <exception>
 #include <functional>
 #include <future>
-#include <iostream>
 #include <kj/async.h>
 #include <kj/async-io.h>
 #include <kj/common.h>
@@ -67,9 +66,10 @@ class TestSetup
 
     TestSetup(bool client_owns_connection = true)
         : thread{[&] {
-              EventLoop loop("mptest", [](mp::LogMessage log_data) {
-                  std::cout << "LOG" << (int)log_data.level << ": " << log_data.message << "\n";
-                  if (log_data.level == mp::Log::Raise) throw std::runtime_error(log_data.message);
+              EventLoop loop("mptest", [](mp::LogMessage log) {
+                  // Info logs are not printed by default, but will be shown with `mptest --verbose`
+                  KJ_LOG(INFO, log.level, log.message);
+                  if (log.level == mp::Log::Raise) throw std::runtime_error(log.message);
               });
               auto pipe = loop.m_io_context.provider->newTwoWayPipe();