## Motivation
The changes made in #3368 to sanitize ANSI control characters to avoid
terminal injection attacks also break colored output and other control
characters that users may legitimately wish to use. There is no mechanism
to disable this sanitization.
## Solution
Add `with_ansi_sanitization` method to allow turning off the sanitization
of ansi output. Sanitizing output remains the default behavior.
Fixes: #3369
## Motivation
This seems to be a result of the new `valueset!` optimisations combined
with this new `record_all!` feature. In fact, the `record_all!` feature never
worked with a set of fields differnt to all a span's fields in the correct order.
The following code panics
```rust
#[test]
fn tracing_bug() {
let span = tracing::info_span!("example", foo=1, bar=2);
tracing::record_all!(span, foo=3);
}
```
## Solution
This is horrible. We rename `valueset!` to `valueset_all!`, then
we re-introduce the original `valueset!` with some notable changes.
The new `valueset!` doesn't use fields from the fieldset iterator, it
instead uses `FieldSet::field(...)` to find the correct field. If the field
isn't found, we set a fallback field that will be ignored (callsites are
not equal).
Fixes#3431
## Motivation
The change merged in #3382 caused a breaking change when released. This
is because users of the tracing macros depend on being able to use a
bare `debug` or `display` function within the macro itself, for example:
```rust
tracing::info!(foo = debug(foo), bar = display(bar));
```
## Solution
This change reverts the breaking part of the original commit, which is
removing the import statement from the `valueset!` macro. However, it
leaves the change to use full module paths inside the macro. E.g.
`$crate::field::debug`. This is best practice, and so worth keeping.
This change also adds a nice warning comment above the import statement
to try and avoid another break happening in the future (because this
isn't the first time that this has happened). It also adds explicit
tests for the use of bare `debug` and `display` usage with the same end.
## Motivation
While investigating #3405, we found that some tests are not being run on
CI. Specifically the `tracing-subscriber` tests that depend on
non-default features.
## Solution
This change adds 2 new `run` commands to the `test-features-stable` CI
job, one with `nextest` and another for the doc tests.
There is also 1 more `run` command to run the `tracing-mock` tests with
all features (which is just `tracing-subscriber` right now, but safer to
set all).
## Motivation
In order to add a regression test, #3379 added support to `tracing-mock`
to expect calls to `on_register_dispatch` for both mock subscribers and
mock layers. A negative integration test for the layer case was included
in #3415. However, there are no negative doctests for this (and as per
my own suggestion, there's no negative test for the subscriber method
either as I wasn't sure it was possible).
## Solution
After a bit of thought, I realised that we could include a negative test
for the `MockSubscriber`. This change adds that test as a doctest, since
we have those in almost all of our documentation and also includes the
already written negative test for the `MockLayer` to a doctest.
## Motivation
The `Layered` implementation of `Subscriber` does not implement and propagate the `on_register_dispatch` callback. This means that combined layers will never have their `on_register_dispatch` methods called.
## Solution
Implement the missing `on_register_dispatch` method.
---------
Co-authored-by: Hayden Stainsby <hds@caffeineconcepts.com>
## Motivation
When `max_files` set to zero,
[rolling.rs:695](c01d4fd9de/tracing-appender/src/rolling.rs (L695))
will cause integer underflow and panicking in debug build. In my
opinion the API should prevent this from happening as "zero" is a
valid `usize` value to pass in.
## Solution
Currently, in release builds, if `max_files` is set to zero, it
behaves just like `u64::MAX` on `x86_64` platforms. Therefore, I
decided to simply make `zero == None`, which should align with the
existing behavior but without the panicking. I believe this can be
considered as "non-breaking".
I'd like to get notifications on these explicitly and I'm doing a lot of
the reviews and maintenance these days, so I think it makes sense.
Also removed Zeki (@zekisherif) as GitHub is telling me that the account
doesn't exist any more.
## Motivation
Continuous profiling on a production workload shows that `Span::enter` is
a significant percent of the samples.
This is currently using `tracing-subscriber = "0.3.19"`.
Concrete numbers:
- 7.7% of samples were found within the stacktrace of a `Span::enter`.
- Of those samples, 22.8% were inside `clone_span`.
- Collectively, that's 1.8% of total CPU time spent in `clone_span` as a result of
`Span::enter`.
## Solution
Remove `clone_span` from `enter`, remove `try_close` from `exit`.
This was originally included to protect against misuse of the `tracing-core` API.
However, there has not been so much use of this low level API as was originally
anticipated, and it is not worth the performance hit.
## Motivation
Using with_subscriber will trigger a panic if the async block creates
a span & enters it on a different thread that will target the default
subscriber. I believe both the with_subscriber AND the enter off-thread
scenario are idiomatic. The reason for the crash is that the span.enter()
try's recording the span exit into the default subscriber which isn't
aware of it since it's registered by the scoped subscriber.
## Solution
From my understanding, it's sufficient for `Registry::exit` just to call
`self.try_close()` and do local bookkeeping:
- The attempt to use the thread dispatcher leads directly to the issues
observed in #3223, and
- I don't think it's correct to call `try_close` on the whole `Layer` stack
at this point anyway, a span being exited is not yet ready to close. All
that is needed is to decrement the reference count within the current
registry.
I've added a test which spawns a thread and enters (and exits, and drops)
a span created on a dispatcher not registered to that thread.
Before this patch, the test fails with the span never being closed
(because there is no thread dispatcher when the span is exited, and so a
reference is leaked in `Registry::exit`).
With this patch, the bookkeeping demonstrated in the test seems correct
to me.
Fixes: #3223
`ValueSet`s contain both a `FieldSet` reference and a slice of
(`&Field`, `Option<&dyn Value>`) pairs. In cases where `ValueSet`s are
generated via documented interfaces (specifically, `tracing::event!` and
other macros), the `Field` references are redundant, because the
`ValueSet` contains a value slot for every field (either a value or
`None`), in the correct order.
As a result, the code generated by the macros is terrible--it must
put a `Field` on the stack for each field--that's 32 bytes per field!
This is a lot of work for apparently no purpose at runtime, and it
can't be moved into a read-only data section since it's intermixed with
dynamic data.
Fix this by adding a variant of `ValueSet` that skips the `Field`
references, knowing that it represents the full set of fields. Keep
the old kind of `ValueSet`, too--it's still needed by `Span::record`,
by old versions of crates, and potentially by third-party crates using
undocumented methods such as `FieldSet::value_set`.
In some adhoc tests on x86_64 Linux, this reduces the code size as
follows:
* One-field event: 258 bytes to 189 bytes, 25% reduction.
* Five-field event: 638 bytes to 276 bytes, **57%** reduction.
* In a larger project with lots of events, ~5% reduction in .text section.
Due to an import of `::tracing::field::{display, debug, Value}`,
macro `valueset!` wasn't sanitary and would produce compile
errors when identifiers `debug` and `display` were used.
This change fixes the issue and makes the macro sanitary.
Fixes: #3381
## Motivation
Making sure the mentioned macro is sanitary and avoiding users
from encountering unexpected compile errors.
## Solution
Removed the import inside macro and used fully-qualified
paths for imported items.
The libsystemd code is documented to determine the syslog
identifier by using
https://man7.org/linux/man-pages/man3/program_invocation_short_name.3.html
(a glibc thing).
This code is parsing via looking at `/proc/self/exe`.
Often, these things are the same, but in my case they're not
because for unfortunate reasons I need to re-exec the current
binary in a tempfile.
It's actually simpler and more reliable for us anyways
to match what libsystemd is doing by looking at argv[0].
Signed-off-by: Colin Walters <walters@verbum.org>
## Motivation
Was reading the docs in the `format` module, and noticed a
couple of typos/missing links, etc.
## Solution
Did a quick pass and tried to fix the above. If I missed something or
the changes are not desired, just let me know!
## Motivation
We would like to apply some Rust 2024 idioms so that, in case of edition
migration, the workload is slightly reduced.
At the very least, this will allow experimentation with latest tracing crates
in `rustc`.
## Solution
Here is a list of applied idioms.
- `-Dwarnings`
- `-Wunused_lifetimes`
- `-Wrustc::internal`
- `-Wunreachable_pub`
- `-Wunused_crate_dependencies`
- `-Wrust_2018_idioms`
- `-Wunsafe_op_in_unsafe_fn`
- `-Wkeyword_idents_2024`
---------
Signed-off-by: Xiangfei Ding <dingxiangfei2009@protonmail.ch>
Co-authored-by: Hayden Stainsby <hds@caffeineconcepts.com>
## Motivation
The `#[instrument]` proc macro only allows setting field names as identifiers, which is not on par with other macros such as `span!` or `event!` that allow constant expressions. Using constants for example can ensure consistency across a project for the field names used.
This addresses #2969, which was already mentioned in this [comment here](https://github.com/tokio-rs/tracing/pull/2617#issuecomment-1718996094) on #2617 (note that "classic macros" mentioned there already work, there are tests attesting of it).
I also updated the doc block to mention field values can be any arbitrary expressions, which was implemented by #672 but never updated.
## Solution
I updated the instrument proc macro to allow constant expressions (const, const fn, literal str, ...) as field names, using the same syntax as #2617, **enclosed in curly braces**.
```rust
const CONST_FIELD_NAME: &str = "foo.bar";
#[instrument(fields({CONST_FIELD_NAME} = "quux"))]
fn fn_const_field_name() {}
```
The behavior around overriding function parameters needed to be
a bit different with const field names, where duplicate fields will
occur if the function parameter isn't explicitly skipped. This is
to avoid any runtime check and may be able to be improved in
future Rust versions.
---------
Co-authored-by: Hayden Stainsby <hds@caffeineconcepts.com>
## Motivation
This PR fixes perf regression (binary size and instruction counts) existed
in tracing > 0.1.37 in case if `release_max_level_*` feature was not set,
but `max_level_*` was.
## Solution
Regression was introduced in #2553, where logic was unintentionally
changed: before pr, in case if `release_max_level_*` wasn't set, log
level from `max_level_*` was used, but after it was unconditionally set
to trace level.
See additional info in https://github.com/tokio-rs/tracing/pull/2553#issuecomment-3262310405
Due to a change in the error messages produced by rustc, one of the UI
tests for failing compilation of the `#[instrument]` attribute when
applied to async functions was failing.
This change updates the expected output so that the test passes.
Some lint failures and errors in core were also fixed.
Co-authored-by: Hayden Stainsby <hds@caffeineconcepts.com>
When using the linux-musl target for rust, the file creation time
cannot be retrieved, as the current version does not support it yet (
This will be fixed with [0]). In the meantime, we parse the datetime
from the filename and use that as a fallback.
Fixes: #2999
[0]: https://github.com/rust-lang/rust/pull/125692
The prune_old_logs function only gets called when we rollover the
appender. The problem is that at startup we create an initial log file
without rolling over, if e.g., the executable then exits before rolling
over for the first time, we never call prune_old_logs.
E.g.: If we have a tracing-appender that rolls over every minute and we
have a max_files parameter of 2. Running the program (which prints a
single log line and exits) every minute, will result in a new log file
everytime without deleting the old ones.
Fixes: #2937
Co-authored-by: Nick Fagerlund <nick@hashicorp.com>
