-
Notifications
You must be signed in to change notification settings - Fork 745
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
subscriber: fix on_event
serialization when no fields set on span
#1333
subscriber: fix on_event
serialization when no fields set on span
#1333
Conversation
Serializing a spans `on_ACTION` events, when no fields are set on the span, results in invalid JSON. This is because `serializier_map` was getting a size hint for `self.0.metadata().fields().len()` then serializing `self.0.fields.field_set()` instead. This resulted in the fields key being set to an empty object, then Serde serializes the k/v pairs from `field_set()`. This was causing an erroneous closing brace `}` to be added after the serialized fields. This change aligns the size hint with the actual serialized data. Refs: tokio-rs#829 (comment)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
thanks for the fix, this looks good to me!
i had one minor suggestion about testing, but i'd be fine to merge this as it is currently if that change seems like a lot of unnecessary effort. up to you!
#[test] | ||
fn json_span_event() { | ||
// Check span events serialize correctly. | ||
// Discussion: /~https://github.com/tokio-rs/tracing/issues/829#issuecomment-661984255 | ||
// | ||
let expected = r#"{"timestamp":"fake time","level":"INFO","fields":{"message":"enter"},"target":"tracing_subscriber::fmt::format::json::test"}"#; | ||
let collector = collector() | ||
.flatten_event(false) | ||
.with_current_span(false) | ||
.with_span_list(false) | ||
.with_span_events(FmtSpan::ENTER); | ||
|
||
test_json(expected, collector, || { | ||
tracing::info_span!("valid_json").in_scope(|| {}); | ||
}); | ||
} | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
take it or leave it, but since the issue here is that we were generating invalid JSON, it might be worth rewriting this test in the same style as the record_works
test? this test actually attempts to parse the output as JSON and then makes assertions about its structure. this could be worth doing, since it would also implicitly assert that the output definitely does parse as JSON.
of course, since the hard-coded JSON string is valid JSON as well, this test is also fine as-is.
…1333) Serializing a spans `on_ACTION` events, when no fields are set on the span, results in invalid JSON. This is because `serializier_map` was getting a size hint for `self.0.metadata().fields().len()` then serializing `self.0.fields.field_set()` instead. This resulted in the fields key being set to an empty object, then Serde serializes the k/v pairs from `field_set()`. This was causing an erroneous closing brace `}` to be added after the serialized fields. This change aligns the size hint with the actual serialized data. Refs: #829 (comment) Co-authored-by: Eliza Weisman <eliza@buoyant.io>
…1333) Serializing a spans `on_ACTION` events, when no fields are set on the span, results in invalid JSON. This is because `serializier_map` was getting a size hint for `self.0.metadata().fields().len()` then serializing `self.0.fields.field_set()` instead. This resulted in the fields key being set to an empty object, then Serde serializes the k/v pairs from `field_set()`. This was causing an erroneous closing brace `}` to be added after the serialized fields. This change aligns the size hint with the actual serialized data. Refs: #829 (comment) Co-authored-by: Eliza Weisman <eliza@buoyant.io>
…1333) Serializing a spans `on_ACTION` events, when no fields are set on the span, results in invalid JSON. This is because `serializier_map` was getting a size hint for `self.0.metadata().fields().len()` then serializing `self.0.fields.field_set()` instead. This resulted in the fields key being set to an empty object, then Serde serializes the k/v pairs from `field_set()`. This was causing an erroneous closing brace `}` to be added after the serialized fields. This change aligns the size hint with the actual serialized data. Refs: #829 (comment) Co-authored-by: Eliza Weisman <eliza@buoyant.io>
Based on feedback by @hawkw, I've improved the test to parse the json output. This is more specifc for the use bug and allows easier testing of the different span state `on_events`. Ref: tokio-rs#1333 (review)
Based on feedback by @hawkw, I've improved the test for tokio-rs#1333 to parse the json output. This is more specifc for the bug and allows easier testing of the different span `on_events`. Ref: tokio-rs#1333 (review)
* subscriber: fix span data for new, exit, and close events New, exit and close span events are generated while the current context is set to either `None` or the parent span of the span the event relates to. This causes spans data to be absent from the JSON output in the case of the `None`, or causes the span data to reference the parent's span data. Changing the way the current span is determined allows the correct span to be identified for these events. Trying to access the events `.parent()` allows access of the correct span for the `on_event` actions, while using `.current_span()` works for normal events. Ref: #1032 * Fix style * subscriber: improve test for #1333 Based on feedback by @hawkw, I've improved the test for #1333 to parse the json output. This is more specifc for the bug and allows easier testing of the different span `on_events`. Ref: #1333 (review) * subscriber: improve #1334 tests covering all span states Use the `on_records` test method check all events have the correct context as described in the PR. * Apply suggestions from code review Co-authored-by: Eliza Weisman <eliza@buoyant.io>
Based on feedback by @hawkw, I've improved the test for #1333 to parse the json output. This is more specifc for the bug and allows easier testing of the different span `on_events`. Ref: #1333 (review)
* subscriber: fix span data for new, exit, and close events New, exit and close span events are generated while the current context is set to either `None` or the parent span of the span the event relates to. This causes spans data to be absent from the JSON output in the case of the `None`, or causes the span data to reference the parent's span data. Changing the way the current span is determined allows the correct span to be identified for these events. Trying to access the events `.parent()` allows access of the correct span for the `on_event` actions, while using `.current_span()` works for normal events. Ref: #1032 * Fix style * subscriber: improve test for #1333 Based on feedback by @hawkw, I've improved the test for #1333 to parse the json output. This is more specifc for the bug and allows easier testing of the different span `on_events`. Ref: #1333 (review) * subscriber: improve #1334 tests covering all span states Use the `on_records` test method check all events have the correct context as described in the PR. * Apply suggestions from code review Co-authored-by: Eliza Weisman <eliza@buoyant.io>
* subscriber: fix span data for new, exit, and close events New, exit and close span events are generated while the current context is set to either `None` or the parent span of the span the event relates to. This causes spans data to be absent from the JSON output in the case of the `None`, or causes the span data to reference the parent's span data. Changing the way the current span is determined allows the correct span to be identified for these events. Trying to access the events `.parent()` allows access of the correct span for the `on_event` actions, while using `.current_span()` works for normal events. Ref: #1032 * Fix style * subscriber: improve test for #1333 Based on feedback by @hawkw, I've improved the test for #1333 to parse the json output. This is more specifc for the bug and allows easier testing of the different span `on_events`. Ref: #1333 (review) * subscriber: improve #1334 tests covering all span states Use the `on_records` test method check all events have the correct context as described in the PR. * Apply suggestions from code review Co-authored-by: Eliza Weisman <eliza@buoyant.io>
# 0.2.18 (April 30, 2021) ### Deprecated - Deprecated the `CurrentSpan` type, which is inefficient and largely superseded by the `registry` API ([#1321]) ### Fixed - **json**: Invalid JSON emitted for events in spans with no fields ([#1333]) - **json**: Missing span data for synthesized new span, exit, and close events ([#1334]) - **fmt**: Extra space before log lines when timestamps are disabled ([#1355]) ### Added - **env-filter**: Support for filters on spans whose names contain any characters other than `{` and `]` ([#1368]) Thanks to @Folyd, and new contributors @akinnane and @aym-v for contributing to this release! [#1321]: #1321 [#1333]: #1333 [#1334]: #1334 [#1355]: #1355 [#1368]: #1368
# 0.2.18 (April 30, 2021) ### Deprecated - Deprecated the `CurrentSpan` type, which is inefficient and largely superseded by the `registry` API ([#1321]) ### Fixed - **json**: Invalid JSON emitted for events in spans with no fields ([#1333]) - **json**: Missing span data for synthesized new span, exit, and close events ([#1334]) - **fmt**: Extra space before log lines when timestamps are disabled ([#1355]) ### Added - **env-filter**: Support for filters on spans whose names contain any characters other than `{` and `]` ([#1368]) Thanks to @Folyd, and new contributors @akinnane and @aym-v for contributing to this release! [#1321]: #1321 [#1333]: #1333 [#1334]: #1334 [#1355]: #1355 [#1368]: #1368
# 0.1.3 (February 4, 2022) This release adds *experimental* support for recording structured field values using the [`valuable`] crate. See [this blog post][post] for details on `valuable`. Note that `valuable` support currently requires `--cfg tracing_unstable`. See the documentation for details. ### Added - **valuable**: Experimental support for serializing user-defined types using [`valuable`] and [`valuable-serde`] ([#1862]) - Support for serializing `f64` values ([#1507]) ### Fixed - Fixed incorrect size hint in `SerializeFieldSet` ([#1333]) - A number of documentation fixes Thanks to @akinnane and @maxburke for contributing to this release! [`valuable`]: https://crates.io/crates/valuable [`valuable-serde`]: https://crates.io/crates/valuable-serde [post]: https://tokio.rs/blog/2021-05-valuable [#1862]: #1862 [#1507]: #1507 [#1333]: #1333 (I also noticed there was a missing changelog entry for v0.1.2, so I fixed that while I was here)
# 0.1.3 (February 4, 2022) This release adds *experimental* support for recording structured field values using the [`valuable`] crate. See [this blog post][post] for details on `valuable`. Note that `valuable` support currently requires `--cfg tracing_unstable`. See the documentation for details. ### Added - **valuable**: Experimental support for serializing user-defined types using [`valuable`] and [`valuable-serde`] ([#1862]) - Support for serializing `f64` values ([#1507]) ### Fixed - Fixed incorrect size hint in `SerializeFieldSet` ([#1333]) - A number of documentation fixes Thanks to @akinnane and @maxburke for contributing to this release! [`valuable`]: https://crates.io/crates/valuable [`valuable-serde`]: https://crates.io/crates/valuable-serde [post]: https://tokio.rs/blog/2021-05-valuable [#1862]: #1862 [#1507]: #1507 [#1333]: #1333 (I also noticed there was a missing changelog entry for v0.1.2, so I fixed that while I was here)
# 0.2.18 (April 30, 2021) ### Deprecated - Deprecated the `CurrentSpan` type, which is inefficient and largely superseded by the `registry` API ([tokio-rs#1321]) ### Fixed - **json**: Invalid JSON emitted for events in spans with no fields ([tokio-rs#1333]) - **json**: Missing span data for synthesized new span, exit, and close events ([tokio-rs#1334]) - **fmt**: Extra space before log lines when timestamps are disabled ([tokio-rs#1355]) ### Added - **env-filter**: Support for filters on spans whose names contain any characters other than `{` and `]` ([tokio-rs#1368]) Thanks to @Folyd, and new contributors @akinnane and @aym-v for contributing to this release! [tokio-rs#1321]: tokio-rs#1321 [tokio-rs#1333]: tokio-rs#1333 [tokio-rs#1334]: tokio-rs#1334 [tokio-rs#1355]: tokio-rs#1355 [tokio-rs#1368]: tokio-rs#1368
# 0.1.3 (February 4, 2022) This release adds *experimental* support for recording structured field values using the [`valuable`] crate. See [this blog post][post] for details on `valuable`. Note that `valuable` support currently requires `--cfg tracing_unstable`. See the documentation for details. ### Added - **valuable**: Experimental support for serializing user-defined types using [`valuable`] and [`valuable-serde`] ([tokio-rs#1862]) - Support for serializing `f64` values ([tokio-rs#1507]) ### Fixed - Fixed incorrect size hint in `SerializeFieldSet` ([tokio-rs#1333]) - A number of documentation fixes Thanks to @akinnane and @maxburke for contributing to this release! [`valuable`]: https://crates.io/crates/valuable [`valuable-serde`]: https://crates.io/crates/valuable-serde [post]: https://tokio.rs/blog/2021-05-valuable [tokio-rs#1862]: tokio-rs#1862 [tokio-rs#1507]: tokio-rs#1507 [tokio-rs#1333]: tokio-rs#1333 (I also noticed there was a missing changelog entry for v0.1.2, so I fixed that while I was here)
Motivation
Serializing a spans
on_ACTION
events, when nofields
are set on the span, results in invalid JSON. This is becauseserializier_map
was getting a size hint forself.0.metadata().fields().len()
then serializingself.0.fields.field_set()
instead. This resulted in thefields
key being set to an empty object, then Serde serializes the k/v pairs fromfield_set()
. This was causing an erroneous closing brace}
to be added after the serialized fields.This is discussed here: #829 (comment)
Solution
This change aligns the size hint with the size of actual serialized data.