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

tracing: fix the "log" feature making async block futures !Send #2073

Merged
merged 7 commits into from
Apr 14, 2022

Conversation

hawkw
Copy link
Member

@hawkw hawkw commented Apr 14, 2022

Motivation

Currently, enabling the log feature can cause a compilation error when
using tracing macros in async functions or blocks. This is because,
when the log feature is enabled, the tracing macros will construct a
log::Record, which is not Send, causing the async fn/block future to
become !Send. This can break compilation when the future is Send
without the log feature enabled. This is really not great, as it makes
the feature no longer purely additive.

Solution

This branch fixes the issue by moving the log::Record construction
behind a function call. Because the log::Record is now only
constructed inside of a function, the log::Record is now never a local
variable within the async block, so it no longer affects the future's
auto traits.

It's kind of a shame that the compiler can't otherwise determine that
the log::Record can never be held across an await point, but sticking
it in a separate function makes this obvious to the compiler. Also, as a
side benefit, this may reduce the size of macro-generated code when the
log feature is enabled a bit, which could improve performance
marginally in some cases.

I added two tests ensuring that async fn and async block futures are
Send when containing tracing macro calls. Previously, on master,
these failed when the log feature is enabled. After this change, the
tests now pass. Thanks to @Noah-Kennedy for the original MCRE these
tests were based on!

Finally, while I was here, I took advantage of the opportunity to clean
up the log integration code a bit. Now that the log::Record
construction is behind a function call in __macro_support, the
LogValueSet type, which is used to wrap a ValueSet and implement
fmt::Display to add it to the textual message of log::Record, no
longer needs to be exposed to the macros, so it can be made properly
private, rather than #[doc(hidden)] pub. Also, I noticed that the
span module implemented its own versions of LogValueSet (FmtAttrs
and FmtValues), which were essentially duplicating the same behavior
for logging span fields. I removed these and changed this code to use
the LogValueSet type instead (which will format string message
fields slightly nicer as well).

Fixes #1793
Fixes #1487

These pass without the `log` feature enabled, but fail when `log` is
enabled. Thanks @Noah-Kennedy for the original MCRE!
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
@hawkw hawkw added kind/bug Something isn't working crate/tracing Related to the `tracing` crate labels Apr 14, 2022
@hawkw hawkw self-assigned this Apr 14, 2022
@hawkw hawkw requested review from davidbarsky and a team as code owners April 14, 2022 17:38
@hawkw hawkw enabled auto-merge (squash) April 14, 2022 17:39
Signed-off-by: Eliza Weisman <eliza@buoyant.io>
@hawkw hawkw merged commit a421763 into master Apr 14, 2022
@hawkw hawkw deleted the eliza/log-send branch April 14, 2022 18:45
hawkw added a commit that referenced this pull request Apr 14, 2022
)

## Motivation

Currently, enabling the `log` feature can cause a compilation error when
using `tracing` macros in async functions or blocks. This is because,
when the `log` feature is enabled, the `tracing` macros will construct a
`log::Record`, which is not `Send`, causing the async fn/block future to
become `!Send`. This can break compilation when the future is `Send`
without the `log` feature enabled. This is really not great, as it makes
the feature no longer purely additive.

## Solution

This branch fixes the issue by moving the `log::Record` construction
behind a function call. Because the `log::Record` is now only
constructed inside of a function, the `log::Record` is now never a local
variable within the async block, so it no longer affects the future's
auto traits.

It's kind of a shame that the compiler can't otherwise determine that
the `log::Record` can never be held across an await point, but sticking
it in a separate function makes this obvious to the compiler. Also, as a
side benefit, this may reduce the size of macro-generated code when the
`log` feature is enabled a bit, which could improve performance
marginally in some cases.

I added two tests ensuring that `async fn` and `async` block futures are
`Send` when containing `tracing` macro calls. Previously, on `master`,
these failed when the `log` feature is enabled. After this change, the
tests now pass. Thanks to @Noah-Kennedy for the original MCRE these
tests were based on!

Finally, while I was here, I took advantage of the opportunity to clean
up the log integration code a bit. Now that the `log::Record`
construction is behind a function call in `__macro_support`, the
`LogValueSet` type, which is used to wrap a `ValueSet` and implement
`fmt::Display` to add it to the textual message of `log::Record`, no
longer needs to be exposed to the macros, so it can be made properly
private, rather than `#[doc(hidden)] pub`. Also, I noticed that the
`span` module implemented its own versions of `LogValueSet` (`FmtAttrs`
and `FmtValues`), which were essentially duplicating the same behavior
for logging span fields. I removed these and changed this code to use
the `LogValueSet` type instead (which will format string `message`
fields slightly nicer as well).

Fixes #1793
Fixes #1487

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
@hawkw hawkw mentioned this pull request Apr 14, 2022
hawkw added a commit that referenced this pull request Apr 14, 2022
)

## Motivation

Currently, enabling the `log` feature can cause a compilation error when
using `tracing` macros in async functions or blocks. This is because,
when the `log` feature is enabled, the `tracing` macros will construct a
`log::Record`, which is not `Send`, causing the async fn/block future to
become `!Send`. This can break compilation when the future is `Send`
without the `log` feature enabled. This is really not great, as it makes
the feature no longer purely additive.

## Solution

This branch fixes the issue by moving the `log::Record` construction
behind a function call. Because the `log::Record` is now only
constructed inside of a function, the `log::Record` is now never a local
variable within the async block, so it no longer affects the future's
auto traits.

It's kind of a shame that the compiler can't otherwise determine that
the `log::Record` can never be held across an await point, but sticking
it in a separate function makes this obvious to the compiler. Also, as a
side benefit, this may reduce the size of macro-generated code when the
`log` feature is enabled a bit, which could improve performance
marginally in some cases.

I added two tests ensuring that `async fn` and `async` block futures are
`Send` when containing `tracing` macro calls. Previously, on `master`,
these failed when the `log` feature is enabled. After this change, the
tests now pass. Thanks to @Noah-Kennedy for the original MCRE these
tests were based on!

Finally, while I was here, I took advantage of the opportunity to clean
up the log integration code a bit. Now that the `log::Record`
construction is behind a function call in `__macro_support`, the
`LogValueSet` type, which is used to wrap a `ValueSet` and implement
`fmt::Display` to add it to the textual message of `log::Record`, no
longer needs to be exposed to the macros, so it can be made properly
private, rather than `#[doc(hidden)] pub`. Also, I noticed that the
`span` module implemented its own versions of `LogValueSet` (`FmtAttrs`
and `FmtValues`), which were essentially duplicating the same behavior
for logging span fields. I removed these and changed this code to use
the `LogValueSet` type instead (which will format string `message`
fields slightly nicer as well).

Fixes #1793
Fixes #1487

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
hawkw added a commit that referenced this pull request Apr 14, 2022
# 0.1.34 (April 14, 2022)

This release includes bug fixes for the "log" support feature and for
the use of both scoped and global default dispatchers in the same
program.

### Fixed

- Failure to use the global default dispatcher when a thread sets a
  local default dispatcher before the global default is set ([#2065])
- **log**: Compilation errors due to `async` block/fn futures becoming
  `!Send` when the "log" feature flag is enabled ([#2073])
- Broken links in documentation ([#2068])

Thanks to @ben0x539 for contributing to this release!

[#2065]: #2065
[#2073]: #2073
[#2068]: #2068
hawkw added a commit that referenced this pull request Apr 14, 2022
# 0.1.34 (April 14, 2022)

This release includes bug fixes for the "log" support feature and for
the use of both scoped and global default dispatchers in the same
program.

### Fixed

- Failure to use the global default dispatcher when a thread sets a
  local default dispatcher before the global default is set ([#2065])
- **log**: Compilation errors due to `async` block/fn futures becoming
  `!Send` when the "log" feature flag is enabled ([#2073])
- Broken links in documentation ([#2068])

Thanks to @ben0x539 for contributing to this release!

[#2065]: #2065
[#2073]: #2073
[#2068]: #2068
hawkw added a commit that referenced this pull request Apr 14, 2022
# 0.1.34 (April 14, 2022)

This release includes bug fixes for the "log" support feature and for
the use of both scoped and global default dispatchers in the same
program.

### Fixed

- Failure to use the global default dispatcher when a thread sets a
  local default dispatcher before the global default is set ([#2065])
- **log**: Compilation errors due to `async` block/fn futures becoming
  `!Send` when the "log" feature flag is enabled ([#2073])
- Broken links in documentation ([#2068])

Thanks to @ben0x539 for contributing to this release!

[#2065]: #2065
[#2073]: #2073
[#2068]: #2068
kangalio added a commit to kangalio/serenity that referenced this pull request Apr 26, 2023
kaffarell pushed a commit to kaffarell/tracing that referenced this pull request May 22, 2024
…kio-rs#2073)

## Motivation

Currently, enabling the `log` feature can cause a compilation error when
using `tracing` macros in async functions or blocks. This is because,
when the `log` feature is enabled, the `tracing` macros will construct a
`log::Record`, which is not `Send`, causing the async fn/block future to
become `!Send`. This can break compilation when the future is `Send`
without the `log` feature enabled. This is really not great, as it makes
the feature no longer purely additive.

## Solution

This branch fixes the issue by moving the `log::Record` construction
behind a function call. Because the `log::Record` is now only
constructed inside of a function, the `log::Record` is now never a local
variable within the async block, so it no longer affects the future's
auto traits.

It's kind of a shame that the compiler can't otherwise determine that
the `log::Record` can never be held across an await point, but sticking
it in a separate function makes this obvious to the compiler. Also, as a
side benefit, this may reduce the size of macro-generated code when the
`log` feature is enabled a bit, which could improve performance
marginally in some cases.

I added two tests ensuring that `async fn` and `async` block futures are
`Send` when containing `tracing` macro calls. Previously, on `master`,
these failed when the `log` feature is enabled. After this change, the
tests now pass. Thanks to @Noah-Kennedy for the original MCRE these
tests were based on!

Finally, while I was here, I took advantage of the opportunity to clean
up the log integration code a bit. Now that the `log::Record`
construction is behind a function call in `__macro_support`, the
`LogValueSet` type, which is used to wrap a `ValueSet` and implement
`fmt::Display` to add it to the textual message of `log::Record`, no
longer needs to be exposed to the macros, so it can be made properly
private, rather than `#[doc(hidden)] pub`. Also, I noticed that the
`span` module implemented its own versions of `LogValueSet` (`FmtAttrs`
and `FmtValues`), which were essentially duplicating the same behavior
for logging span fields. I removed these and changed this code to use
the `LogValueSet` type instead (which will format string `message`
fields slightly nicer as well).

Fixes tokio-rs#1793
Fixes tokio-rs#1487

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
kaffarell pushed a commit to kaffarell/tracing that referenced this pull request May 22, 2024
# 0.1.34 (April 14, 2022)

This release includes bug fixes for the "log" support feature and for
the use of both scoped and global default dispatchers in the same
program.

### Fixed

- Failure to use the global default dispatcher when a thread sets a
  local default dispatcher before the global default is set ([tokio-rs#2065])
- **log**: Compilation errors due to `async` block/fn futures becoming
  `!Send` when the "log" feature flag is enabled ([tokio-rs#2073])
- Broken links in documentation ([tokio-rs#2068])

Thanks to @ben0x539 for contributing to this release!

[tokio-rs#2065]: tokio-rs#2065
[tokio-rs#2073]: tokio-rs#2073
[tokio-rs#2068]: tokio-rs#2068
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
crate/tracing Related to the `tracing` crate kind/bug Something isn't working
Projects
None yet
2 participants