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

Add a wrapper to trace queries issued by 'compute_ctl'. #3390

Closed
wants to merge 1 commit into from

Conversation

hlinnaka
Copy link
Contributor

This allows more fine-grained tracing of how much time each query takes during compute startup.

The tracing is done in a new wrapper crate around the 'postgres' crate, so that it's as transparent as possible to the calling code. The wrapper could be used elsewhere too, but for now it's only used in 'compute_ctl'.

@hlinnaka hlinnaka requested a review from a team as a code owner January 20, 2023 11:16
@hlinnaka hlinnaka requested review from tychoish and removed request for a team January 20, 2023 11:16
@hlinnaka
Copy link
Contributor Author

I did this originally as part of #3353, but it actually stands on its own so it seems best to consider it separately.

@hlinnaka hlinnaka requested review from LizardWizzard and funbringer and removed request for tychoish January 20, 2023 11:18
@hlinnaka hlinnaka changed the title Add a wrapper to log queries issued by 'compute_ctl'. Add a wrapper to trace queries issued by 'compute_ctl'. Jan 20, 2023
This allows more fine-grained tracing of how much time each query
takes during compute startup.

The tracing is done in a new wrapper crate around the 'postgres'
crate, so that it's as transparent as possible to the calling
code. The wrapper could be used elsewhere too, but for now it's only
used in 'compute_ctl'.
Comment on lines +70 to +72
/// function, with `config.deref().connect()`, and bypass the tracing. That's
/// not easy to do by accident, though, so we accept it.
impl std::ops::Deref for TracingConfig {
Copy link
Contributor

@funbringer funbringer Jan 24, 2023

Choose a reason for hiding this comment

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

Unfortunately, that's pretty easy to do by accident using any reference to the original type, because deref coercions are ubiquitous, .e.g fn worker(arg: &postgres::Config). Thus, "It is a nice way to enforce that all your calls go through the wrappers." is not correct, because we can't enforce that, at least not with this impl.

Speaking of #[instrument], is there any meaningful distinction between query_one or query_raw from the standpoint of a person looking at the dashboard? We could have some abstract span run_query(sql, params) instead.

Per tracing's doc:

A function annotated with #[instrument] will create and enter a span with that function’s name every time the function is called, with arguments to that function will be recorded as fields using fmt::Debug.
...
You can also use skip_all to skip all arguments.

Which means we'll have query_one, query_this, query_that and friends, and none of those spans will contain the query we're trying to measure (per skip_all), right? How does one know what they're measuring, then? Or am missing something?

To sum up, the impl itself is very verbose. Maybe we should add ad-hoc annotations to the call sites, instead? Doesn't sound like a big PR.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Unfortunately, that's pretty easy to do by accident using any reference to the original type, because deref coercions are ubiquitous, .e.g fn worker(arg: &postgres::Config). Thus, "It is a nice way to enforce that all your calls go through the wrappers." is not correct, because we can't enforce that, at least not with this impl.

Good point. I could just add all the functions to TracingConfig, but I wanted to avoid the typing :-(. I don't think this can be achieved with macros either. There's no way to iterate through the functions implemented in an existing struct, defined in another crate, AFAIK. In practice, compute_ctl uses only few of the functions, so maybe I'll implement just the ones that are needed right now, and if someone needs more config options in the future, add them to TracingConfig at that point.

Or maybe it's OK as it is? The idea with this crate is that you don't need to depend on the 'postgres' crate at all, only 'tracing_postgres'. If you don't list 'postgres' in your Cargo.toml at al, then a function like fn worker(arg: &postgres::Config) will not compile. The danger still exists if you use yet another crate that contains a function like that, but it's less likely.

What do you think?

Speaking of #[instrument], is there any meaningful distinction between query_one or query_raw from the standpoint of a person looking at the dashboard? We could have some abstract span run_query(sql, params) instead.

Sure.

Per tracing's doc:

A function annotated with #[instrument] will create and enter a span with that function’s name every time the function is called, with arguments to that function will be recorded as fields using fmt::Debug. ... You can also use skip_all to skip all arguments.

Which means we'll have query_one, query_this, query_that and friends, and none of those spans will contain the query we're trying to measure (per skip_all), right? How does one know what they're measuring, then? Or am missing something?

Correct, the SQL query is not included in the traces of those functions. You can still see the timing, and by looking at the code and the surrounding context you can figure out which query it is, but I agree it would be nice to include the query.

Unfortunately the 'query' argument in these functions is a generic ToStatement, which doesn't implement Debug.

Hmm, but I guess we could have one more wrapper, TracingStatement, and make it work with that. I'll try that.

To sum up, the impl itself is very verbose. Maybe we should add ad-hoc annotations to the call sites, instead? Doesn't sound like a big PR.

There are quite a lot of queries already, and it's easy to forget to annotate one. I'd still prefer a transparent wrapper approach, even if it's a lot of boilerplate code. That way, all the extra code is tucked away in a separate crate, and the interesting codepaths are shorter and simpler to read.

Copy link
Contributor

@funbringer funbringer Jan 25, 2023

Choose a reason for hiding this comment

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

Or maybe it's OK as it is? The idea with this crate is that you don't need to depend on the 'postgres' crate at all, only 'tracing_postgres'. If you don't list 'postgres' in your Cargo.toml at al, then a function like fn worker(arg: &postgres::Config) will not compile.

I'm afraid there's one more problem: you don't have to name this type, all you have to do is to call deref to erase the wrapper. This could happen in a generic code; For instance, if there's a trait implemented for postgres::Config one could make it work for this wrapper just by calling deref, silently mangling the desired side-effect. In conclusion, this solution will likely work 90% of the time, but occasionally we'll have to scratch our heads intensely.

In practice, compute_ctl uses only few of the functions, so maybe I'll implement just the ones that are needed right now, and if someone needs more config options in the future, add them to TracingConfig at that point.

Yes, that could be one option. Generally I'd start small and then expand later. Chances are what we really need is a bespoke "loggable query/ops manager" abstraction, not the raw connection interface with benefits. I mean, I can totally see the appeal of a low-level wrapper sharing the same API (we're thinking inheritance as in oop), but to properly incapsulate it you'd have to eliminate deref, which is more work. On the other hand, we have two more options:

  • Implement this directly in rust-postgres, per below (it's a good contribution that can't go wrong).
  • Implement a higher level abstraction i.e. "ops manager", probably with "one true way to register and describe queries" which would mandate the desired observability. Then we'd likely need to have 2-3 trace points + extra bounds (T: Display). This plays along with the idea that we might not need the whole API covered. Another benefit is that we control everything, top to bottom, which is good in of itself (I also dislike being handicapped due to sealed "secret sauce" traits and other bs like that).

Correct, the SQL query is not included in the traces of those functions. You can still see the timing, and by looking at the code and the surrounding context you can figure out which query it is, but I agree it would be nice to include the query.

Unfortunately the 'query' argument in these functions is a generic ToStatement, which doesn't implement Debug.

We could mandate ToStatement + Debug, though, because we're the ones writing those queries.

@hlinnaka
Copy link
Contributor Author

Or perhaps we should bite the bullet and add tracing directly into the 'tokio-postgres' crate. There'd be some interest for that in upstream, anyway. sfackler/rust-postgres#642.

@LizardWizzard
Copy link
Contributor

As discussed moving to draft

@LizardWizzard LizardWizzard marked this pull request as draft March 21, 2023 18:04
@LizardWizzard
Copy link
Contributor

Removing myself as a reviewer for now. Fell free to re-request when this is ready

@LizardWizzard LizardWizzard removed their request for review March 22, 2023 08:53
@hlinnaka
Copy link
Contributor Author

This isn't going anywhere in its current form, so closing.

@hlinnaka hlinnaka closed this Apr 28, 2023
@bayandin bayandin deleted the tracing-postgres-wrapper branch May 19, 2023 13:06
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.

3 participants