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

subscriber: Reorder JSON fields #892

Merged
merged 1 commit into from
Aug 20, 2020
Merged

subscriber: Reorder JSON fields #892

merged 1 commit into from
Aug 20, 2020

Conversation

bryanburgers
Copy link
Contributor

Motivation

JSON is a structured format, so the order of the fields should be
unimportant.

However, sometimes the JSON output is read in non-structured or
semi-structured contexts, and sometimes the output is truncated. In
those situations, when the spans and the current span are serialized
before the fields and the message, it makes it very difficult to see
what is going on.

Solution

By serializing the "fields" key before the "spans" and "span" keys, this
information is more likely visible when the payload is shown raw and
gets truncated.

Systems that parse the JSON as structured data should be unaffected
because of the nature of JSON.

Fixes #891

@bryanburgers bryanburgers requested review from hawkw and a team as code owners August 6, 2020 14:04
Copy link
Member

@hawkw hawkw left a comment

Choose a reason for hiding this comment

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

I had one note about the behavior when flatten_event is true. Other than that, this looks good to me!

Comment on lines 220 to 223
if !self.format.flatten_event {
use tracing_serde::fields::AsMap;
serializer.serialize_entry("fields", &event.field_map())?;
}
Copy link
Member

@hawkw hawkw Aug 17, 2020

Choose a reason for hiding this comment

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

If we are not flattening the event's fields into the root JSON object, it looks like we will now emit the fields first, llike this:

{
    "timestamp": "Feb 20 11:28:15.096",
    "level": "INFO",
    "fields": {"message":"some message","key":"value"},
    "target":" mycrate",
    "span": {"name": "leaf"},
    "spans": [{"name":"root"},{"name":"leaf"}],
}

But if we are flattening the event fields, it looks like the fields are still last, so it will look like this:

{
    "timestamp":"Feb 20 11:28:15.096",
    "level":"INFO",
    "target":"mycrate",
    "span":{"name": "leaf"},
    "spans":[{"name": "root"},{"name": "leaf"}],
    "message":"some message",
    "key":"value"
}

Do you think we should maybe move the code from the else here

} else {
let mut visitor = tracing_serde::SerdeMapVisitor::new(serializer);
event.record(&mut visitor);
visitor.finish()
}
to up here, as well, so that the ordering is consistent regardless of flattening?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Sure! I had to introduce a new function to SerdeMapVisitor to return the underlying serializer back to the caller to make this work – hopefully that's not a problem!


I'm not sure if the JSON standard specifies any particular action when a key appears twice. Both Firefox and Chrome seem to use the last specified value:

  • JSON.parse('{ "target": "mycrate", "target": "practice" }') will return { "target": "practice" }
  • JSON.parse('{ "target": "practice", "target": "mycrate" }') will return { "target": "mycrate" }

So this could be considered a breaking change in the pathological case where a consumer with flattening on emits a key that is one of the known keys.

event!(Level::INFO, archer = "Bob", bow = "yew", arrow = "dx-487", target = "practice", hit = "bullseye");

Copy link
Member

Choose a reason for hiding this comment

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

Sure! I had to introduce a new function to SerdeMapVisitor to return the underlying serializer back to the caller to make this work – hopefully that's not a problem!

Okay, that's fine, we'll just have to make sure to publish a new tracing-serde release before we can publish a new tracing-subscriber. Not a problem, just making a note of this.

I'm not sure if the JSON standard specifies any particular action when a key appears twice. Both Firefox and Chrome seem to use the last specified value:

* `JSON.parse('{ "target": "mycrate", "target": "practice" }')` will return `{ "target": "practice" }`

* `JSON.parse('{ "target": "practice", "target": "mycrate" }')` will return `{ "target": "mycrate" }`

So this could be considered a breaking change in the pathological case where a consumer with flattening on emits a key that is one of the known keys.

Hmm. That could be an issue. The names "target" and "file", which appear in the metadata, are both potentially common enough that I think potential clashes with a field name might be worth worrying about. We might want to make other changes (out of scope for this PR) to handle this when the fields are being flattened...maybe prefixing the metadata fields with "metadata_" or something? Of course, that would break the JSON format as well, so it would have to wait for 0.3 before we can address it.

## Motivation

JSON is a structured format, so the order of the fields should be
unimportant.

However, sometimes the JSON output is read in non-structured or
semi-structured contexts, and sometimes the output is truncated. In
those situations, when the spans and the current span are serialized
before the fields and the message, it makes it very difficult to see
what is going on.

## Solution

By serializing the "fields" key before the "spans" and "span" keys, this
information is more likely visible when the payload is shown raw and
gets truncated.

Systems that parse the JSON as structured data should be unaffected
because of the nature of JSON.
@hawkw
Copy link
Member

hawkw commented Aug 20, 2020

Looks good to me! @LucioFranco, do you wanna take a look as well?

@hawkw hawkw merged commit c518e1a into tokio-rs:master Aug 20, 2020
@bryanburgers bryanburgers deleted the json-fields-before-spans branch September 1, 2020 13:45
hawkw added a commit that referenced this pull request Sep 8, 2020
Fixed

- **env-filter**: Fixed a regression where `Option<Level>` lost its
  `Into<LevelFilter>` impl ([#966])
- **env-filter**: Fixed `EnvFilter` enabling spans that should not be
  enabled when multiple subscribers are in use ([#927])

Changed

- **json**: `format::Json` now outputs fields in a more readable order
  ([#892])
- Updated `tracing-core` dependency to 0.1.16

Added

- **fmt**: Add `BoxMakeWriter` for erasing the type of a `MakeWriter`
  implementation ([#958])
- **fmt**: Add `TestWriter` `MakeWriter` implementation to support
  libtest output capturing ([#938])
- **layer**: Add `Layer` impl for `Option<T> where T: Layer` ([#910])
- **env-filter**: Add `From<Level>` impl for `Directive` ([#918])
- Multiple documentation fixes and improvements

Thanks to @Pothulapati, @samrg472, @bryanburgers, @keetonian, and
@SriRamanujam for contributing to this release!

[#927]: #927
[#966]: #966
[#958]: #958
[#892]: #892
[#938]: #938
[#910]: #910
[#918]: #918
hawkw added a commit that referenced this pull request Sep 9, 2020
# 0.2.12 (September 8, 2020)

### Fixed

- **env-filter**: Fixed a regression where `Option<Level>` lost its
  `Into<LevelFilter>` impl ([#966])
- **env-filter**: Fixed `EnvFilter` enabling spans that should not be enabled
  when multiple subscribers are in use ([#927])
  
### Changed

- **json**: `format::Json` now outputs fields in a more readable order ([#892])
- Updated `tracing-core` dependency to 0.1.16

### Added

- **fmt**: Add `BoxMakeWriter` for erasing the type of a `MakeWriter`
  implementation ([#958])
- **fmt**: Add `TestWriter` `MakeWriter` implementation to support libtest
  output capturing ([#938])
- **layer**: Add `Layer` impl for `Option<T> where T: Layer` ([#910])
- **env-filter**: Add `From<Level>` impl for `Directive` ([#918])
- Multiple documentation fixes and improvements

Thanks to @Pothulapati, @samrg472, @bryanburgers, @keetonian, 
and @SriRamanujam for contributing to this release!

[#927]: #927
[#966]: #966
[#958]: #958
[#892]: #892
[#938]: #938
[#910]: #910
[#918]: #918
hawkw added a commit that referenced this pull request Sep 11, 2020
Added

- `SerdeMapVisitor::finish` to complete serializing the visited objects
  (#892)
- `SerdeMapVisitor::take_serializer` to return the serializer wrapped by
  a `SerdeMapVisitor` (#892)

Thanks to @bryanburgers for contributing to this release!
hawkw added a commit that referenced this pull request Sep 11, 2020
### Added

- `SerdeMapVisitor::finish` to complete serializing the visited objects
  (#892)
- `SerdeMapVisitor::take_serializer` to return the serializer wrapped by
  a `SerdeMapVisitor` (#892)

Thanks to @bryanburgers for contributing to this release!
Sign up for free to 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.

Proposal: Reorder JSON fields
3 participants