Add log levels and advertise them to users via logging callback

theuni commented at 9:13 pm on September 29, 2025: contributor

Fixes #215. Alternative to #216.

This is is implemented roughly as suggested here:

Adds log levels.
Adds an additional “Raise” log level.
Uses the ‘Trace’ level by default, so existing behavior is unchanged.
Remains backwards-compatible via a new (deprecated) EventLoop constructor.

Users should not observe any behavioral difference. However, they can now change the log level (using the EventLoop constructor which takes a LogOptions) to set a lower level.

Once merged, Core should take advantage of the new functionality:

Update the callback function signature.
Set the requested log level.
Map mp log levels to Core ones inside the callback.

DrahtBot commented at 9:13 pm on September 29, 2025: none

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	ryanofsky

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#218 (Better error and log messages by ryanofsky)

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.

theuni renamed this:
~~Better logging~~
Add log levels and advertise them to users via logging callback
on Sep 29, 2025

ryanofsky commented at 10:20 am on September 30, 2025: collaborator

Code review ACK 72ed9d96964dede514b00ffc7861a0bbb2a1c710. Looks good in current form, but I do have a number of suggestions, which could be followups:

Would be nice to have just a single MP_LOG macro instead of a collection of macros as suggested. The only thing we need macros for is conditional evaluation. Other logging features are better handled by C++ code. Practically speaking, I think we are going to want more log options beyond just levels to control what is logged, and we will probably want to allow log sink classes other than the event loop to provide more context. For example it’d be nice to pass a Connection object or possible Request object instead of an EventLoop object to MP_LOG as the log sink, and log extra connection & request information, or only conditionally log for certain connections or requests. And it’d be nice to allow logging directives in .capnp files so individual classes or methods could be annotated with logging categories or other information. Like if IPC is used by mining and gui clients, it would be nice to enable logging for just mining events, or a specific subset of GUI events, instead of all IPC calls. It could also be nice to have a log sink that logs the current source location (file/function/line number). I’d like it to be possible to make these changes by simply modifying the Logger class and not having to refactor a collection of macros. This is the reason for defining MP_LOG as a simple forwarding macro in the suggestion. I also think there can be other advantages to avoiding macros like providing clearer compile errors.
I’m not sure why Logger class needs to be movable, or why it requires separate enabled state. I.e. is there a use-case for m_fn being null and enabled being true? These are implementation details that could be simplified later, though.
Maybe prefer to call Exception level Raise or Throw. To me, MP_LOGEXCEPTION sounds like something that should be used to log an exception that has already happened, not like something that should be used to trigger one. MP_LOG(Log::Throw, loop) looks more like something that would throw an exception. (Also for background, it may not be clear why there is an exception-throwing feature. The reason is that I wanted applications using libmultiprocess like Bitcoin core to not need their application code to be compiled with libmultiprocess as a dependency. This means that when there are IPC errors like connections being broken, client exceptions need to be constructed by the application, so node/wallet/GUI code can be built just referencing local exception types not using libmultiprocess or capnproto type definitions.)
Would be nice to rename LogLevel to just Log so log prints could be a little shorter like: MP_LOG(Log::Info, loop) << "something something". I also feel like the exception level is not really a level, and more of a behavior flag. And I could also imagine other flags like Log::RateLimit being defined for progress messages that should be rate limited. A simple Log:: prefix seems good enough whatever logging flag might be needed.
Would be nice to not to break the API so it is easier to bump bitcoin subtree and not have to include bitcoin core changes in the libmultiprocess merge commit, or introduce a broken commit that doesn’t compile. Seems like it should be possible to do this by keeping the EventLoop(std::function<void(bool, std::string)> log_fn) constructor unchanged, and setting options.log_fn = [log_fn](level, message) { log_fn(level == Exception, msesage); } when it is called.

theuni commented at 2:46 pm on September 30, 2025: contributor

Would be nice to have just a single MP_LOG macro instead of a collection of macros as suggested.

Sure, no preference here. Happy to do that.

I’m not sure why Logger class needs to be movable, or why it requires separate enabled state. I.e. is there a use-case for m_fn being null and enabled being true? These are implementation details that could be simplified later, though.

The constructor changes started as a bugfix, and I just finished them up for the sake of completion. Unless I’m misreading, currently in master, if moved, the moved-from logger will invoke the callback with an empty buffer.

I don’t have a use-case in mind… I can just disable moving if you’d prefer.

As for the enabled variable, I agree it’s unnecessary and awkward. I considered just setting m_fn to nullptr if disabled, but decided the intention of the code was more clear with a separate variable. Happy to change this if you’d prefer.

Maybe prefer to call Exception level Raise or Throw. To me, MP_LOGEXCEPTION sounds like something that should be used to log an exception that has already happened, not like something that should be used to trigger one. MP_LOG(Log::Throw, loop) looks more like something that would throw an exception. (Also for background, it may not be clear why there is an exception-throwing feature. The reason is that I wanted applications using libmultiprocess like Bitcoin core to not need their application code to be compiled with libmultiprocess as a dependency. This means that when there are IPC errors like connections being broken, client exceptions need to be constructed by the application, so node/wallet/GUI code can be built just referencing local exception types not using libmultiprocess or capnproto type definitions.)

Thanks, that’s helpful context. And indeed, I was confused about why this error was not a raise().

Would be nice to rename LogLevel to just Log so log prints could be a little shorter like: MP_LOG(Log::Info, loop) << "something something". I also feel like the exception level is not really a level, and more of a behavior flag. And I could also imagine other flags like Log::RateLimit being defined for progress messages that should be rate limited. A simple Log:: prefix seems good enough whatever logging flag might be needed.

No problem with renaming. And yeah, I went back and forth on the exception level question.

Would be nice to not to break the API so it is easier to bump bitcoin subtree and not have to include bitcoin core changes in the libmultiprocess merge commit, or introduce a broken commit that doesn’t compile. Seems like it should be possible to do this by keeping the EventLoop(std::function<void(bool, std::string)> log_fn) constructor unchanged, and setting options.log_fn = [log_fn](level, message) { log_fn(level == Exception, msesage); } when it is called.

Clever, I can do that.

For the sake of getting this in more quickly, I’m going to punt on the implementation details for now and just focus on the API changes. I do agree (or at least, don’t strongly disagree) with all of your suggestions, so I’d be happy to do them as a follow-up.

Thinking about this more, for future-proofing, I think it’d be good for the callback to simply take a LogData struct which could be extended in the future as needed, without having to change the function signature again. That would allow us to punt on some of the implementation details for now. Specifically, I’d propose:

0namespace mp {
1  struct LogData {
2    std::string message;
3    LogLevel level;
4    // Future flags and stuff.
5  };
6
7  using LogFn = std::function<void(LogData)>;
8}

Thoughts?

ryanofsky commented at 4:35 pm on September 30, 2025: collaborator

The constructor changes started as a bugfix, and I just finished them up for the sake of completion. Unless I’m misreading, currently in master, if moved, the moved-from logger will invoke the callback with an empty buffer.

I don’t have a use-case in mind… I can just disable moving if you’d prefer.

Makes sense, and nice to fix that bug. I think I’d want to disable moving unless there is a reason to have it, but fine either way.

As for the enabled variable, I agree it’s unnecessary and awkward. I considered just setting m_fn to nullptr if disabled, but decided the intention of the code was more clear with a separate variable. Happy to change this if you’d prefer.

Yeah seems fine either way, but could be nice to get rid of. Especially if move & assignments functions go away and there is reduced boilerplate in general.

Thanks, that’s helpful context. And indeed, I was confused about why this error was not a raise().

I think this one is not a raise because point of raising is to return individual exceptions to clients that they can handle and potentially recover from. If taskFailed raised an exception, because it is called from the event loop thread, I think that would end the whole event loop and break all IPC connections, which could be an overreaction. There may be a better way to make this customizable though.

Thinking about this more, for future-proofing, I think it’d be good for the callback to simply take a LogData struct which could be extended in the future as needed, without having to change the function signature again.

I like that idea. I think I might call the struct LogMessage instead of LogData just to be more descriptive, and because I"m a little allergic to suffixes like Info and Data that don’t indicate anything specific.

PR looks good as is, but any of these changes would be welcome if you want to implement them. Thanks for finding the issue and providing this nice solution.

theuni force-pushed on Sep 30, 2025

theuni commented at 5:15 pm on September 30, 2025: contributor

I just went ahead and implemented all of the feedback from above. Sorry for the substantial diff from the last push, just figured it’d be better to get it all knocked out in one go :)

Major changes:

Logger now just takes a const reference to the loop’s LogOptions. If necessary in the future (for other structures with different lifetimes), this can just be a copy.
Renamed LogLevel to Log and Exception to Raise.
Dropped the m_enabled variable, now calculated on-the-fly.
Dropped level-specific macros.
MP_LOG and MP_LOGPLAIN now just forward their parameters along.
The logging callback now passes a lone mp::LogMessage parameter.
Added a back-compat constructor as suggested.

theuni force-pushed on Sep 30, 2025

ryanofsky approved

ryanofsky commented at 2:40 pm on October 1, 2025: collaborator

Code review ACK cd00f72358de4798e7e7a61a977e09a82c9a3d40. Looks very good.

Notes for possible followups, could:

Remove deprecated Eventloop constructor
Rename MP_LOGPLAIN to MP_LOG, have Logger constructor take log destination objects other than Eventloop
- Different destination objects could prepend thread names, request numbers, etc
- Destination variables could make serverInvoke and clientInvoke code more readable
Maybe add streaming helpers to support automatically formatting structs and applying max_chars, and maybe support conditional output like << LogAt(Log::Trace, [&](auto& logger) { logger << response; }

theuni commented at 4:36 pm on October 1, 2025: contributor

Notes for possible followups, could:

Agree with all of these.

Here’s a branch ready for PR’ing into Core to take advantage of the changes here: https://github.com/theuni/bitcoin/commits/libmultiprocess-logging-bump/

ryanofsky commented at 5:33 pm on October 1, 2025: collaborator

Thanks, I’ll go ahead and merge this today and open a subtree bump PR for bitcoin. If we want these changes to be in v30 (which is sounds like you do?) I believe I will also need to open up a separate subtree bump PR for the 30.x branch, assuming marco’s comment in https://github.com/bitcoin/bitcoin/issues/33439#issuecomment-3346073946 is right.

I could add your commits from https://github.com/theuni/bitcoin/commits/libmultiprocess-logging-bump/ to the subtree bump PR too, though it seems like it might be less confusing if that was a separate PR. Happy to do whatever you prefer,

Would still welcome more reviews here if anyone wants to look. Looking around at other changes that could be merged: #213 and #214 seem ready and #212, #218, and #221 could also be ready if reviewed.

in include/mp/proxy-io.h:119 in cd00f72358 outdated

115+
116+    //! The severity level of this message
117+    Log level;
118+};
119+
120+using LogFn = std::function<void(LogMessage)>;

sipa commented at 5:38 pm on October 1, 2025:

Do we want to pass LogMessage by value? It’s 40 bytes here, while I think the normal advice is max 2 pointers worth for objects passed by value.

ryanofsky commented at 6:11 pm on October 1, 2025:

const LogMessage& could make sense semantically. Only disadvantage might be that if log handler wanted to move the string or message into another data structure, it would no longer be able to do that, and would need to copy it instead. Probably a log handler would not do that, but it’s not inconceivable. Maybe LogMessage&& would make more sense?

I’m guessing choice doesn’t matter too much since cost of moving the struct should be small compared to cost of invoking the function through a pointer and actually formatting the log message. And it should be possible to change the type without breaking compatibility later, so anything here seems fine.

theuni commented at 6:46 pm on October 1, 2025:

Only disadvantage might be that if log handler wanted to move the string or message into another data structure, it would no longer be able to do that, and would need to copy it instead. Probably a log handler would not do that, but it’s not inconceivable. Maybe LogMessage&& would make more sense?

This was my thinking as well. And since libmultiprocess always calls this function from Logger’s dtor (just before the string is erased), it will always be move constructed. LogMessage&& would be fine too, but I don’t see much upside there, and tend to reserve that for universal references unless there’s some meaningful difference.

theuni commented at 6:36 pm on October 1, 2025: contributor

Thanks, I’ll go ahead and merge this today and open a subtree bump PR for bitcoin. If we want these changes to be in v30 (which is sounds like you do?) I believe I will also need to open up a separate subtree bump PR for the 30.x branch, assuming marco’s comment in bitcoin/bitcoin#33439 (comment) is right.

I agree in principle, seems like having a branch for v30 makes sense just generally speaking.

But for now at least, looking at libmultiprocess master, I don’t see the harm in just bumping to everything in master + this pr? Everything since the last bump seems pretty straightforward, unless there’s some potential for a regression that I’m not seeing?

I could add your commits from https://github.com/theuni/bitcoin/commits/libmultiprocess-logging-bump/ to the subtree bump PR too, though it seems like it might be less confusing if that was a separate PR. Happy to do whatever you prefer,

I could go ahead and open a PR for my branch, then rebase after the bump. That way we can get parallel review with a separation of concerns.

Would still welcome more reviews here if anyone wants to look. Looking around at other changes that could be merged: #213 and #214 seem ready and #212, #218, and #221 could also be ready if reviewed.

Thanks, will have a look.

ryanofsky commented at 7:08 pm on October 1, 2025: collaborator

But for now at least, looking at libmultiprocess master, I don’t see the harm in just bumping to everything in master + this pr? Everything since the last bump seems pretty straightforward, unless there’s some potential for a regression that I’m not seeing?

Yes I think we want to backport all libmultiprocess changes into the 30.x release branch, or none of them as discussed in #33439, and avoid doing something more complicated like cherry-picking.

So far no libmultiprocess changes have been backported since the branch was created, but it should not be a problem to do that. I just need to create two bitcoin PRs instead of one.

I could go ahead and open a PR for my branch, then rebase after the bump. That way we can get parallel review with a separation of concerns.

Sounds good, that’d be helpful

ryanofsky commented at 0:36 am on October 2, 2025: collaborator

Hmm, I was about to merge this but didn’t realize there was a silent merge conflict with #214. Do you think you could rebase?

Will close and reopen to trigger CI. Sorry for not noticing this before.

ryanofsky closed this on Oct 2, 2025

ryanofsky reopened this on Oct 2, 2025

Logging: Add an EventLoop constructor to allow for user-specified log options 83a2e10c0b

Logging: Disable moving or copying Logger 463a8296d1

Logging: add log levels to mirror Core's

For now, all messages are reported at Log::Info.

d0a1ba7ebf

Logging: Disable logging if messsage level is less than the requested level 67b092d835

Logging: Use new logging macros

The Info log level is still used for all messages other than exceptions.

Also remove now-unused log functions.

408874a78f

Logging: Break out expensive log messages and classify them as Trace e4de0412b4

Logging: reclassify remaining log messages 213574ccc4

Logging: Pass LogData struct to logging callback

The previous logging callback signature is deprecated and support will be
removed in a future release.

Also adds a <functional> include to calculator example to make IWYU happy.

515ce93ad3

theuni force-pushed on Oct 2, 2025

theuni commented at 3:41 am on October 2, 2025: contributor

Done. Fixed the silent conflict. Diff from the rebase is just:

 0diff --git a/include/mp/type-context.h b/include/mp/type-context.h
 1index 0ca3579..09ac179 100644
 2--- a/include/mp/type-context.h
 3+++ b/include/mp/type-context.h
 4@@ -153,7 +153,7 @@ auto PassField(Priority<1>, TypeList<>, ServerContext& server_context, const Fn&
 5                 MP_LOG(*server.m_context.loop, Log::Debug)
 6                     << "IPC server post request  #" << req << " {" << thread.m_thread_context.thread_name << "}";
 7                 if (!thread.m_thread_context.waiter->post(std::move(invoke))) {
 8-                    server.m_context.loop->log()
 9+                    MP_LOG(*server.m_context.loop, Log::Error)
10                         << "IPC server error request #" << req
11                         << " {" << thread.m_thread_context.thread_name << "}" << ", thread busy";
12                     throw std::runtime_error("thread busy");

ryanofsky approved

ryanofsky commented at 10:24 am on October 2, 2025: collaborator

Code review ACK 515ce93ad349380ff44e2141009d4aa7c9545654. Just rebased and fixed compile error caused by new log print since last review

ryanofsky merged this on Oct 2, 2025

ryanofsky closed this on Oct 2, 2025

ryanofsky referenced this in commit 3f74b5aa02 on Oct 2, 2025

ryanofsky referenced this in commit 5bb3cbdfba on Oct 2, 2025

ryanofsky referenced this in commit 5191781886 on Oct 7, 2025

ryanofsky referenced this in commit 0f01e1577f on Oct 7, 2025

ryanofsky referenced this in commit abcd4c4ff9 on Oct 7, 2025

Sjors referenced this in commit 3e34afe882 on Oct 7, 2025

fanquake referenced this in commit becf150013 on Oct 10, 2025

Sjors referenced this in commit 7e61dcfa61 on Oct 10, 2025

glozow referenced this in commit db4bde0b03 on Oct 14, 2025

fanquake referenced this in commit a14e7b9dee on Oct 16, 2025

Add log levels and advertise them to users via logging callback #220

Reviews

Conflicts