Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Add copy buttons to all
 blocks\n(function() {\n function addCopyButtons() {\n document.querySelectorAll('pre code').forEach(function(codeBlock) {\n if (codeBlock.parentElement.hasAttribute('data-copy-added')) return;\n codeBlock.parentElement.setAttribute('data-copy-added', 'true');\n \n var btn = document.createElement('button');\n btn.textContent = 'Copy';\n btn.style.cssText = 'position:absolute;top:4px;right:4px;padding:2px 8px;font-size:11px;background:#4ecdc4;border:none;border-radius:4px;color:#1a1a2e;cursor:pointer;opacity:0.7;transition:opacity 0.2s;';\n btn.onmouseover = function() { this.style.opacity = '1'; };\n btn.onmouseout = function() { this.style.opacity = '0.7'; };\n btn.onclick = function() {\n navigator.clipboard.writeText(codeBlock.textContent).then(function() {\n btn.textContent = 'Copied!';\n setTimeout(function() { btn.textContent = 'Copy'; }, 1500);\n });\n };\n codeBlock.parentElement.style.position = 'relative';\n codeBlock.parentElement.appendChild(btn);\n });\n }\n \n addCopyButtons();\n \n // Re-run on dynamic content\n var observer = new MutationObserver(addCopyButtons);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Add Copy Buttons to Code Blocks");
}
} catch(__e) { console.warn('[Userscript:Add Copy Buttons to Code Blocks]', __e); }
})();
(function(){
try {
var __m = "github.com";
var __re = new RegExp('^' + "github\\.com" + '
Skip to content

Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Force GitHub README to respect dark mode\n(function() {\n var style = document.createElement('style');\n style.textContent = '\n .markdown-body {\n color-scheme: dark light;\n }\n .markdown-body pre { background: #161b22 !important; }\n .markdown-body code { background: rgba(110, 118, 129, 0.4) !important; }\n .markdown-body table th, .markdown-body table td { border-color: #30363d !important; }\n .markdown-body img { background: #0d1117; }\n .markdown-body blockquote { border-left-color: #8b949e; }\n .markdown-body hr { border-color: #30363d; }\n ';\n document.head.appendChild(style);\n})();", "GitHub Dark Mode README Fix"); } } catch(__e) { console.warn('[Userscript:GitHub Dark Mode README Fix]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Highlight search terms from Google/DuckDuckGo/Bing referrer\n(function() {\n var ref = document.referrer;\n var terms = [];\n \n if (ref.includes('google.com') || ref.includes('duckduckgo.com') || ref.includes('bing.com')) {\n var url = new URL(ref);\n var q = url.searchParams.get('q') || url.searchParams.get('p');\n if (q) {\n terms = q.split(/\\s+/).filter(function(t) { return t.length > 2; });\n }\n }\n \n if (terms.length === 0) return;\n \n var style = document.createElement('style');\n style.textContent = '.userscript-highlight { background: #fbbf24; color: #1a1a2e; padding: 1px 3px; border-radius: 2px; }';\n document.head.appendChild(style);\n \n function highlight(node) {\n if (node.nodeType === 3) { // text node\n var text = node.textContent;\n var found = false;\n terms.forEach(function(term) {\n var regex = new RegExp('(' + term.replace(/[.*+?^${}()|[\\]\\\\]/g, '\\\\') + ')', 'gi');\n if (regex.test(text)) {\n found = true;\n var frag = document.createDocumentFragment();\n var parts = text.split(regex);\n parts.forEach(function(part, i) {\n if (i % 2 === 0) {\n frag.appendChild(document.createTextNode(part));\n } else {\n var span = document.createElement('span');\n span.className = 'userscript-highlight';\n span.textContent = part;\n frag.appendChild(span);\n }\n });\n node.parentNode.replaceChild(frag, node);\n }\n });\n } else if (node.nodeType === 1 && node.childNodes) { // element\n var skipTags = ['SCRIPT', 'STYLE', 'NOSCRIPT', 'TEXTAREA', 'INPUT', 'SELECT'];\n if (!skipTags.includes(node.tagName)) {\n Array.from(node.childNodes).forEach(highlight);\n }\n }\n }\n \n highlight(document.body);\n \n // Re-highlight on dynamic content\n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1 || node.nodeType === 3) highlight(node);\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Highlight Search Terms"); } } catch(__e) { console.warn('[Userscript:Highlight Search Terms]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Strip utm_, fbclid, gclid, etc. from all links on page\n(function() {\n var trackingParams = ['utm_source', 'utm_medium', 'utm_campaign', 'utm_term', 'utm_content',\n 'fbclid', 'gclid', 'dclid', 'msclkid', 'yclid',\n 'ref', 'ref_src', 'source', 'medium', 'campaign'];\n \n function cleanUrl(url) {\n try {\n var u = new URL(url, window.location.origin);\n var changed = false;\n trackingParams.forEach(function(p) {\n if (u.searchParams.has(p)) {\n u.searchParams.delete(p);\n changed = true;\n }\n });\n return changed ? u.toString() : url;\n } catch (e) {\n return url;\n }\n }\n \n function cleanLinks() {\n document.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n \n cleanLinks();\n \n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1) {\n if (node.tagName === 'A') cleanLinks();\n node.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Remove Tracking Parameters from Links"); } } catch(__e) { console.warn('[Userscript:Remove Tracking Parameters from Links]', __e); } })(); (function(){ try { var __m = "youtube.com"; var __re = new RegExp('^' + "youtube\\.com" + '
Skip to content

Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Auto-enable theater mode on YouTube\n(function() {\n function tryTheater() {\n var btn = document.querySelector('button[aria-label=\"Theater mode\"], ytd-player #player button[title=\"Theater mode\"]');\n if (btn && !btn.classList.contains('activated')) {\n btn.click();\n }\n }\n \n // Try immediately\n tryTheater();\n \n // Try after navigation (SPA)\n var lastUrl = location.href;\n setInterval(function() {\n if (location.href !== lastUrl) {\n lastUrl = location.href;\n setTimeout(tryTheater, 500);\n }\n }, 1000);\n \n // Also try on player load\n var observer = new MutationObserver(tryTheater);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "YouTube Theater Mode Default"); } } catch(__e) { console.warn('[Userscript:YouTube Theater Mode Default]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Remove or un-stick sticky/fixed headers that block content\n(function() {\n function unstick() {\n document.querySelectorAll('header, nav, [role=\"banner\"], .header, .navbar, .sticky, .fixed-top, [style*=\"position: fixed\"], [style*=\"position:sticky\"]').forEach(function(el) {\n if (el.style.position === 'fixed' || el.style.position === 'sticky' || \n getComputedStyle(el).position === 'fixed' || getComputedStyle(el).position === 'sticky') {\n el.style.position = 'static';\n el.style.top = 'auto';\n el.style.zIndex = 'auto';\n }\n });\n }\n \n unstick();\n \n var observer = new MutationObserver(unstick);\n observer.observe(document.body, { childList: true, subtree: true, attributes: true, attributeFilter: ['style', 'class'] });\n})();", "Kill Sticky Headers"); } } catch(__e) { console.warn('[Userscript:Kill Sticky Headers]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Universal Dark Mode - works on any site\n(function() {\n var enabled = true;\n \n function applyDarkMode() {\n if (!enabled) return;\n \n // Create style element if it doesn't exist\n var style = document.getElementById('universal-dark-mode-style');\n if (!style) {\n style = document.createElement('style');\n style.id = 'universal-dark-mode-style';\n document.head.appendChild(style);\n }\n \n // Dark mode CSS - inverts colors but preserves images/video\n style.textContent = '\n /* Invert everything except media */\n html {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #1a1a2e !important;\n }\n \n /* Restore images, videos, iframes, canvas */\n img, video, iframe, canvas, svg, picture, [style*=\"background-image\"] {\n filter: invert(1) hue-rotate(180deg) !important;\n }\n \n /* Preserve specific elements that should not be inverted */\n .no-dark-mode, .no-dark-mode *,\n [data-theme=\"light\"], [data-theme=\"light\"],\n .ace_editor, .ace_editor *,\n .CodeMirror, .CodeMirror *,\n .monaco-editor, .monaco-editor *,\n .markdown-body pre, .markdown-body pre *,\n .highlight, .highlight *,\n pre code, pre code * {\n filter: none !important;\n }\n \n /* Fix common UI elements */\n .modal, .popup, .dropdown-menu, .tooltip, .popover {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #2d2d44 !important;\n border-color: #444 !important;\n }\n \n /* Scrollbars */\n ::-webkit-scrollbar { background: #1a1a2e !important; }\n ::-webkit-scrollbar-thumb { background: #444 !important; }\n ::-webkit-scrollbar-thumb:hover { background: #555 !important; }\n \n /* Selection */\n ::selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ::-moz-selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ';\n }\n \n function removeDarkMode() {\n var style = document.getElementById('universal-dark-mode-style');\n if (style) style.remove();\n }\n \n // Toggle with Alt+Shift+D\n document.addEventListener('keydown', function(e) {\n if (e.altKey && e.shiftKey && e.key === 'D') {\n e.preventDefault();\n enabled = !enabled;\n if (enabled) {\n applyDarkMode();\n console.log('[Universal Dark Mode] Enabled');\n } else {\n removeDarkMode();\n console.log('[Universal Dark Mode] Disabled');\n }\n }\n });\n \n // Apply on load\n applyDarkMode();\n \n // Re-apply on dynamic content\n var observer = new MutationObserver(function(mutations) {\n if (enabled && !document.getElementById('universal-dark-mode-style')) {\n applyDarkMode();\n }\n });\n observer.observe(document.head, { childList: true });\n \n console.log('[Universal Dark Mode] Loaded - Press Alt+Shift+D to toggle');\n})();", "Universal Dark Mode"); } } catch(__e) { console.warn('[Userscript:Universal Dark Mode]', __e); } })(); })();
Skip to content

Logging and spans via thread-local storage - #4223

Closed
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger
Closed

Logging and spans via thread-local storage#4223
joostjager wants to merge 3 commits into
lightningdevkit:mainfrom
joostjager:tls-logger

Conversation

@joostjager

@joostjagerjoostjager commented Nov 13, 2025

Copy link
Copy Markdown
Contributor

This PR adds the ability to open a logger scope that stores the Logger instance in thread-local storage. This avoids the need to thread through a logger and associated type parameter to every method that needs to log.

A logger scope can also be given a name and logging Records now contain the names of the surrounding scopes.

Example log output:

node 0 TRACE [lightning::sign::tx_builder:435] ch:97fe52 [send_payment] ...including to_local output with value 98762 [p:02888f h:72cd6e]
node 0 TRACE [lightning::chain::chainmonitor:1407] ch:97fe52 [send_payment] Updating ChannelMonitor to id 1 [p:02888f]
node 0 INFO [lightning::chain::channelmonitor:4214] ch:97fe52 [send_payment->update_monitor] Applying update, bringing update_id from 0 to 1 with 1 change(s). [p:02888f]
node 0 TRACE [lightning::chain::channelmonitor:4277] ch:97fe52 [send_payment->update_monitor] Updating ChannelMonitor with latest counterparty commitment transaction info [p:02888f]
node 0 DEBUG [lightning::chain::chainmonitor:1451] ch:97fe52 [send_payment] Persistence of ChannelMonitorUpdate id 1 completed [p:02888f]
node 0 DEBUG [lightning::ln::channelmanager:5336] ch:97fe52 [send_payment] Channel is open and awaiting update, resuming it [p:02888f]

@ldk-reviews-bot

Copy link
Copy Markdown

👋 Hi! I see this is a draft PR.
I'll wait to assign reviewers until you mark it as ready for review.
Just convert it out of draft status when you're ready for review!

@joostjagerjoostjager changed the title Add LoggerScopeAdd LoggerScope for a thread-local Logger instanceNov 13, 2025
@codecov

codecovBot commented Nov 13, 2025

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 84.96503% with 43 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.34%. Comparing base (de384ff) to head (7dd7d6f).
⚠️ Report is 571 commits behind head on main.

Files with missing linesPatch %Lines
lightning/src/chain/channelmonitor.rs83.33%23 Missing ⚠️
lightning/src/util/logger.rs75.00%3 Missing and 6 partials ⚠️
lightning-macros/src/lib.rs73.07%6 Missing and 1 partial ⚠️
lightning/src/chain/onchaintx.rs91.11%4 Missing ⚠️
Additional details and impacted files
@@ Coverage Diff @@## main #4223 +/- ##
=======================================
Coverage 89.33% 89.34% =======================================
Files 180 180 Lines 139042 139082 +40 Branches 139042 139082 +40 =======================================
+ Hits 124219 124264 +45 + Misses 12196 12193 -3 + Partials 2627 2625 -2 
FlagCoverage Δ
fuzzing36.04% <47.86%> (+0.07%)⬆️
tests88.70% <84.96%> (-0.01%)⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I played with this a bit, sadly Rust doesn't allow you to convert an arbitrary (?Sized) trait impl to dyn Trait (as it could lead to building a vtable that points to a type that has another vtable, which they could support by copying the vtable but do not). Thus, the real way to achieve this would be to convert the Deref<Target=Logger> bounds with Deref<Target=dyn Logger> (allowing us to simply deref the passed logger to get a dyn Logger). That's an annoying repetitive task so I asked claude to do it, but after fighting with it for a while it found that bounding on the dyn Logger results in objects that aren't Send/Sync making them not-multi-threaded, and then it immediately reset all its work and told me that I shouldn't want to do that:

The original design is actually more flexible and correct for Rust's type system. The generic bound doesn't prevent users from passing trait objects - it just doesn't require them, which is necessary for compatibility with different trait object variants.

(of course the log::Log trait is always Send + Sync-bounded to work around this issue). Luckily we have MaybeSend + MaybeSync for this purpose, so I made claude do that [1]. Anyway, once you get that far using the new LoggerScope is pretty doable (even in a trivial proc-macro [2], which could eventually push a scope onto the logger).

[1] https://git.bitcoin.ninja/?p=rust-lightning;a=shortlog;h=refs/heads/claude/2025-11-dyn-logger

[2]

/// Adds a logging scope at the top of a method.
#[proc_macro_attribute]
pub fn log_scope(_attrs: TokenStream, meth: TokenStream) -> TokenStream {
let mut meth = if let Ok(parsed) = parse::<syn::ItemFn>(meth) {
parsed
} else {
return (quote! {
compile_error!("log_scope can only be set on methods")
})
.into();
};
let init_context = quote! { let _logging_context = crate::util::logger::LoggerScope::new(&*self.logger); };
meth.block.stmts.insert(0, parse(init_context.into()).unwrap());
quote! { #meth }.into()
}

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I've tried to make it work on top of your Maybe* commit, but failed. I can't get rid of

1066 | let _scope = LoggerScope::new(&*self.logger); // DOES NOT WORK
| ---------------- ^^^^^^^^^^^^^ doesn't have a size known at compile-time
| |
| required by a bound introduced by this call

First I thought you wanted to bound everything on dyn Logger to prevent the nested vtable, but that's not in your commit.

Proc macro for logger scope is interesting, and can indeed be extended with a node id in testing.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

The type passed to LoggerScope::new needs to change to take a &'a dyn Logger rather than taking a concrete Logger.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

@joostjager

joostjager commented Nov 17, 2025

Copy link
Copy Markdown
ContributorAuthor

I am wondering what the performance implications are of the logger scope. Just adding a node id in TLS would test-only, but storing the logger instance itself is production code that wouldn't be running if there was a global logger instead.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I don't think its going to be material in either direct. Storing a dyn Logger in TLS shouldn't be more than like an extra 2 or 3 pointers (just 1 for the vtable, one for the self?) per thread. The existing logic was an extra ~1 pointer per logger object stored in various places (generally as Deref impls are usually just a single pointer). The dyn version requires jumping through the vtable indirection (and reading the vtable jump pointer from memory) so there's a tiny hit, but it shouldn't be substantial on any Real Hardware, really. TLS is a bit screwy on older rustc (and in C) on MacOS IIRC, but I assume by now that's all resolved.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

I had tried that, but it didn't work. Same sized error. Pushed the commit. Maybe I am doing something wrong.

Right, looks like claude just forgot to update the NetworkGraph logger bound to dyn.

@TheBlueMatt

Copy link
Copy Markdown
Collaborator

Oh, claude didn't update any of the references to dyn lol. Dumb LLMs just ignore half of what you tell them, I hadn't bothered to look at what it did, either. Anyway, gotta update all those bounds!

@joostjager

Copy link
Copy Markdown
ContributorAuthor

With bound L: Deref<Target = dyn Logger + MaybeSend + MaybeSync> the code works indeed.

I started a bit of creative search/replace across the repo to do a sweeping conversion (https://github.com/lightningdevkit/rust-lightning/compare/main...joostjager:rust-lightning:dyn-logger?expand=0). Needs a bit more work.

It's probably not necessary for deciding on the direction we want to take this to.

@joostjagerjoostjager self-assigned this Nov 20, 2025
@joostjager
joostjagerforce-pushed the tls-logger branch 9 times, most recently from ee40265 to d3f7e4dCompareDecember 3, 2025 14:13
Reduce boiler plate for logging, and allow quick insertion of log
statements anywhere without first threading through a logger instance
and associated type parameter.
@joostjagerjoostjager changed the title Add LoggerScope for a thread-local Logger instanceLogging using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging using a thread-local instanceLogging and spans using a thread-local instanceDec 3, 2025
@joostjagerjoostjager changed the title Logging and spans using a thread-local instanceLogging and spans via thread-local storageDec 3, 2025
Demonstrating how the proc macro can be used to set a thread-local
logger at a public entry point. The scope name is also picked up and
logged via log statements that still have an explicit logger
instance.
@joostjager

Copy link
Copy Markdown
ContributorAuthor

Sadly it seems that thread-local storage isn't compatible with no std. It's very unfortunate that I realized that only now that this PR is nearly finished. Spans can probably be implemented without thread-local storage, but getting rid of the logger parameters seems to be impossible. Even a global logger is problematic in no std because it requires the logger to be sync.

@joostjager

Copy link
Copy Markdown
ContributorAuthor

I don't see this happening as long as we keep the current logging system

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@joostjager@ldk-reviews-bot@TheBlueMatt