Migrate from log to tracing

[hdevalence]

Hi, in Zebra https://github.com/ZcashFoundation/zebra we used @hawkw's tracing rather than log and wrote our own TracingComponent.

Would Abscissa be interested in upstreaming (a modified version of) that component and replacing the default log component with a tracing-based one? In contrast to log, tracing is much more async-friendly, but can remain compatible with log-based crates.

There are some design questions, if this turns out to be of interest to Abscissa:

1. One of the really killer features of tracing is dynamic filter reloading -- how should this be exposed to Abscissa applications?

2. In Zebra, we have an HTTP endpoint that allows feeding inputs to the filter reloading. Should Abscissa provide a default mechanism for doing filter reloading? My guess is no, that this is application-specific (e.g., we will probably fold ours into the standard RPC interface).

[tarcieri]

Absolutely. I've been independently very interested in replacing the current logging component with tracing.

One of the really killer features of tracing is dynamic filter reloading -- how should this be exposed to Abscissa applications?

My initial thought would be to expose a method on the tracing component allowing modification of the filter. When you want to modify it, look up the tracing component in the component registry, and call the method.

In Zebra, we have an HTTP endpoint that allows feeding inputs to the filter reloading. Should Abscissa provide a default mechanism for doing filter reloading? My guess is no, that this is application-specific (e.g., we will probably fold ours into the standard RPC interface).

It might potentially be interesting to have a separate reusable component for this, but it probably doesn't belong in abscissa_core.

[hawkw]

Hi! I just thought I'd swing by and mention that if you have any questions about migrating to tracing, I'm happy to help out, just let me know!

Also, a couple things I thought I'd mention:

Since you're currently using log, there's a pair of feature flags in tracing that enable outputting log records from tracing spans and events, potentially in addition to emitting traces. This is intended primarily for libraries where some users are using log – it's possible to maintain backwards-compatibility for users expecting abscissa to emit log records.

In Zebra, we have an HTTP endpoint that allows feeding inputs to the filter reloading. Should Abscissa provide a default mechanism for doing filter reloading? My guess is no, that this is application-specific (e.g., we will probably fold ours into the standard RPC interface).

It might potentially be interesting to have a separate reusable component for this, but it probably doesn't belong in abscissa_core.

This seems like the right approach to me. Since a couple projects have implemented this kind of endpoint, I'd like there to be a tracing crate that provides a reusable implementation of it — I think an abscissa component could be implemented on top of that?

[tarcieri]

I think an abscissa component could be implemented on top of that?

Yup. Components can just be lightweight wrappers for other crates which handle initialization/lifecycle management (they are in part modeled after Ruby on Rails' Railties)

[hdevalence]

Cool, so if I'm reading all of these comments correctly it sounds like:

1. The current LogComponent built into Abscissa could be refactored into a TracingComponent that uses tracing. This component would have a method that allows reloading the filter.

2. Another optional component could provide an HTTP endpoint that receives filter directives. This could wrap a tracing-endpoint crate rather than having its own implementation, and could be done subsequently to and separately from (1).

Does that sound right?

One remaining question I have is whether the TracingComponent should emit log events, as @hawkw suggested. Since Abscissa is intended for binaries, I'm not sure if it makes sense to be compatible with downstream users expecting log events, since (at least the way I understand Abscissa) the Abscissa binary is the ultimate downstream user. Is that correct @tarcieri?

[hawkw]

One remaining question I have is whether the TracingComponent should emit log events, as @hawkw suggested. Since Abscissa is intended for binaries, I'm not sure if it makes sense to be compatible with downstream users expecting log events, since (at least the way I understand Abscissa) the Abscissa binary is the ultimate downstream user. Is that correct @tarcieri?

Ah, okay, this belies my relative lack of knowledge about Abscissa; I wasn't sure whether it was typically used as a library where the user has control over fn main, or if Abscissa took control over fn main. In that case, we would probably want to have an adapter in the other direction instead, so that user code can call into libraries which emit log records and have those records exist within the trace tree.

[tarcieri]

@hdevalence

Does that sound right?

Yep, exactly! You can effectively just delete the current LogComponent (and for that matter, pretty much everything in the current logging module) and replace it with a TracingComponent that boots up at the same point in the application lifecycle.

Re 2) 👍

One remaining question I have is whether the TracingComponent should emit log events, as @hawkw suggested.

For me, it's very important to continue to receive and emit events logged through the log facade. There are a lot of libraries we use which log important information through its facade, and I wouldn't want to lose that.

@hawkw

In that case, we would probably want to have an adapter in the other direction instead, so that user code can call into libraries which emit log records and have those records exist within the trace tree.

Yep, exactly!

[hdevalence]

@tarcieri receive and emit? I definitely see the usecase for receiving log events – exactly the one you mentioned – but I'm less clear on why an Abscissa binary would need to emit log events.

[tarcieri]

@hdevalence sorry, just "receive", i.e. messages logged by 3rd party libraries through the log facade need to show up in tracing.

This looks like the relevant functionality:

https://docs.rs/tracing-log/0.1.1/tracing_log/#convert-log-records-to-tracing-events

[hdevalence]

Yep, we do exactly that in Zebra's TracingComponent already, but I just wanted to check in case there was something I was missing re: emitting log events. I think I'll be out of time today but I can try to work on this next week.

[tarcieri]

Awesome!

[hdevalence]

Starting work on this today.

[hdevalence]

Made a draft PR with some unresolved points, linked above :)

[hdevalence]

This was a breaking API change -- is there anything else that should be included before a new version is released?

[tarcieri]

I'd like to do a migration from lazy_static to once_cell, which eliminates the need for macros, better fits the general initialization pattern Abscissa uses, and seems to stand a pretty good chance of making it into the standard library.

Other than that, I'd say it's ready to ship.