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

Expose tracing-log's metadata normalization system #2043

Closed
wants to merge 2 commits into from

Conversation

CAD97
Copy link
Contributor

@CAD97 CAD97 commented Apr 2, 2022

@hawkw, can I have little a code crimes, as a treat?

Motivation

I'm piping a linked library's logging callbacks into tracing. The callbacks provide file/line/func/message, which maps nicely into the log crate's model of log events, and equally fine into tracing, but because I'm using tracing, I can't provide dynamic file/line/module into the events to be logged, so instead attach them as structured fields.

Solution

Tracing-log already does this for log records, so this "just" exposes and slightly extends/generalizes the practice to support arbitrary user implementations of runtime-normalized metadata.

In short, this works by sniffing the metadata name, rather than identifing a specific known callsite just for tracing-log. After the magic metadata name is found, event fields are extracted based on more magic names to fill in the runtime metadata contents, and any remaining fields are passed along to the end consumer.

@CAD97 CAD97 requested review from hawkw, carllerche, davidbarsky and a team as code owners April 2, 2022 00:46
@CAD97 CAD97 marked this pull request as draft April 2, 2022 00:46
@CAD97
Copy link
Contributor Author

CAD97 commented Apr 2, 2022

(Ah, whoops, this was meant to be marked as a draft.)

This is essentially a proof-of-concept that this works, but likely wants a number of changes to actually be upstreamed, not the least of which is new tests and examples of using the functionality.

@CAD97
Copy link
Contributor Author

CAD97 commented Apr 2, 2022

Also, after putting in work to do things "the right way" for tracing-filter, it was nice to be able to sit back and just make something work for a bit.

Can I have little a code crimes, as a treat?

In short, this works by sniffing the metadata name, rather than
identifing a specific known callsite just for tracing-log.
After the magic metadata name is found, event fields are extracted based
on more magic names to fill in the runtime metadata contents, and any
remaining fields are passed along to the end consumer.
@CAD97
Copy link
Contributor Author

CAD97 commented Apr 3, 2022

I have a commit using this in my project that motivated it here. It does seem to work, but the magic fields are still printed by the formatters, rather than being filtered out. I haven't yet figured out what conspiring is going on to hide the fields from regular log records, or, rather, why it doesn't work on this branch.

The "proper"/"better" way would be to utilize the normalized metadata's
FieldSet and only record fields seen in that fieldset, but this is what
is already done, and works fine, so *shrug emoji*

Technically tracing-log doesn't specify that field magic starts with the
name magic, but we're smuggling crimes anyway and it does so
@CAD97
Copy link
Contributor Author

CAD97 commented Apr 3, 2022

Found it! To illustrate the benefits of using this patch, here's a comparison:

(Mapping func to module_path, which goes unused by fmt. Losing the line number for some undiagnosed reason...)

Before, default fmt:

2022-04-03T06:51:35.647444Z  WARN fmod: fmod: file="e:\\jk\\workspace\\Build__2.2__API_Win\\core_api\\platforms\\win\\src\\fmod_os_misc.cpp" line=86 func="FMOD_OS_Init" COM not initialized on this thread, call CoInitializeEx(nullptr, COINIT_APARTMENTTHREADED) to avoid this.

After, default fmt:

2022-04-03T06:53:08.805205Z  WARN fmod: fmod:     COM not initialized on this thread, call CoInitializeEx(nullptr, COINIT_APARTMENTTHREADED) to avoid this.

Before, pretty fmt:

  2022-04-03T06:52:21.305732Z  WARN fmod: file: "e:\\jk\\workspace\\Build__2.2__API_Win\\core_api\\platforms\\win\\src\\fmod_os_misc.cpp", line: 86, func: "FMOD_OS_Init", COM not initialized on this thread, call CoInitializeEx(nullptr, COINIT_APARTMENTTHREADED) to avoid this.
    at crates\fmod-rs\src\error.rs:304
    in fmod::fmod

After, pretty fmt:

  2022-04-03T06:52:49.494152Z  WARN fmod: COM not initialized on this thread, call CoInitializeEx(nullptr, COINIT_APARTMENTTHREADED) to avoid this.
    at e:\jk\workspace\Build__2.2__API_Win\core_api\platforms\win\src\fmod_os_misc.cpp
    in fmod::fmod

With that, I think I'm done with the PoC, and I need to ask whether this is a use case that tracing wants to support at all, and if so, how we want to go about it (in terms of API design, anyway; smuggling the normalization in fields seems the way to go).

@CAD97 CAD97 marked this pull request as ready for review April 3, 2022 07:00
@CAD97 CAD97 requested a review from jtescher as a code owner April 3, 2022 07:00
@CAD97
Copy link
Contributor Author

CAD97 commented Apr 3, 2022

(Also doing this for Span would be interesting, as it would allow me to translate the callback's func to a span. Semantically, though, I don't know if that's right; it probably semantically maps better to module_path.)

@CAD97
Copy link
Contributor Author

CAD97 commented Jun 14, 2022

While this is more backwards-compatible (as in, at all) than #2048, I'm going to close this PR for the time being in favor of just keeping #2048 up to date.

@CAD97 CAD97 closed this Jun 14, 2022
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.

1 participant