Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bug: LocalPool swallowing logs in iroh-blobs tests #2589

Closed
wants to merge 2 commits into from

Conversation

ramfox
Copy link
Contributor

@ramfox ramfox commented Aug 5, 2024

Description

While investigating the flaky CI failure of the localpool::test_drop test, I found an example of LocalPool eating logging.

The logs inside the test_drop print, but any logs written in LocalPool::spawn_detached are lost.

run cargo test --package iroh-blobs test_drop -- --nocapture to view.

I also had to change from using tracing_subscriber::fmt::try_init() to iroh_test::logging::setup() in the test to get ANY logging to show.

Related to #2577

Notes & open questions

Change checklist

  • Self-review.
  • Documentation updates following the style guide, if relevant.
  • Tests if relevant.
  • All breaking changes documented.

Copy link

github-actions bot commented Aug 5, 2024

Documentation for this PR has been generated and is available at: https://n0-computer.github.io/iroh/pr/2589/docs/iroh/

Last updated: 2024-08-05T17:28:43Z

@@ -568,6 +572,7 @@ mod tests {
tokio::time::sleep(Duration::from_millis(100)).await;
// drop x at the end. we will never get here when the future is
// no longer polled, but drop should still be called
tracing::debug!("Dropping {x:?}");
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@dignifiedquire should this line still be caught in logging? It's not currently.

@flub
Copy link
Contributor

flub commented Aug 6, 2024

Still looking into this. FWIW the iroh_test::logging::setup has never worked with tests using multiple threads, so that's not really any different with the LocalPool.

The problem with using a global subscriber is that all tests use the same subscriber and IIRC your tests output starts flowing into the wrong tests due to how test isolation and output capturing works.

flub added a commit that referenced this pull request Sep 17, 2024
This preserves the tracing subscriber that is installed in the current
thread when the LocalPool is created.  It then installs it into every
thread managed by the pool, ensuring that tracing output from the pool
is preserved.

Maybe this should be configurable, though since this is just an
internal tool for us I think we're fine just always having this
behaviour.

Fixes #2589
@flub
Copy link
Contributor

flub commented Sep 17, 2024

Oops, I thought this was an issue and it's a PR... I replaced this in #2735

github-merge-queue bot pushed a commit that referenced this pull request Sep 17, 2024
## Description

This preserves the tracing subscriber that is installed in the current
thread when the LocalPool is created.  It then installs it into every
thread managed by the pool, ensuring that tracing output from the pool
is preserved.

## Breaking Changes

Why is this even pub?  But fine:

`iroh_blobs::util::local_pool::LocalPool` will now install the tracing
subscriber of the thread creating the pool, into each thread managed
by the pool.  Practically this should not break any code already
managing their tracing subscribers either manually inside tasks or by
setting a global subscriber before creating the pool.  But if you
really liked the behaviour of swallowing the logs on doing this it's a
breaking change.

## Notes & open questions

Maybe this should be configurable, though since this is just an
internal tool for us I think we're fine just always having this
behaviour.

Fixes #2577 
Replaces #2589

## Change checklist

- [x] Self-review.
- [x] Documentation updates following the [style
guide](https://rust-lang.github.io/rfcs/1574-more-api-documentation-conventions.html#appendix-a-full-conventions-text),
if relevant.
- [x] Tests if relevant.
- [x] All breaking changes documented.
@flub
Copy link
Contributor

flub commented Sep 17, 2024

The other PR did get merged

@flub flub closed this Sep 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Archived in project
Development

Successfully merging this pull request may close these issues.

3 participants