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

slow query log: only use Instant::now when needed + refactor #1110

Merged
merged 2 commits into from
Apr 18, 2024

Conversation

Centril
Copy link
Contributor

@Centril Centril commented Apr 18, 2024

Description of Changes

  • Refactor the slow query logger to reuse WorkloadType and other refactoring.
  • Try to regain some of the performance lost in incr-select (see below).

After 7d5eb15 compared to 7d5eb1532db173c032afa6b46b013148aec132c5~1:

Benchmarking incr-select: Collecting 100 samples in estimated 5.0
incr-select             time:   [226.69 ns 228.30 ns 230.24 ns]
                        change: [+24.989% +26.097% +27.045%] (p = 0.00 < 0.05)
                        Performance has regressed.

After this PR compared to 7d5eb1532db173c032afa6b46b013148aec132c5~1:

Benchmarking incr-select: Collecting 100 samples in estimated 5.0
incr-select             time:   [195.23 ns 195.55 ns 196.04 ns]
                        change: [+7.5233% +8.3927% +9.1255%] (p = 0.00 < 0.05)
                        Performance has regressed.

Run on i7-7770K, 64GB RAM.
As you can see, this recovers some of the +26% lost in performance such that +8.4% is lost instead.
The primary reason for the performance loss was the unconditional Instant::now which results in a system call.
This call is now conditional on whether there's also a threshold.

API and ABI breaking changes

None

Expected complexity level and risk

1

Testing

No semantic changes.

@Centril Centril mentioned this pull request Apr 18, 2024
3 tasks
@Centril Centril force-pushed the centril/slow-query-incr-select branch from 80e1d6a to f7d35dc Compare April 18, 2024 11:13
Copy link
Contributor

@mamcx mamcx left a comment

Choose a reason for hiding this comment

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

LGTM

@joshua-spacetime
Copy link
Collaborator

Thanks for catching this @Centril. I'll take a look shortly. You're correct that we shouldn't be making any system calls per eval_incr.

Copy link
Collaborator

@joshua-spacetime joshua-spacetime left a comment

Choose a reason for hiding this comment

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

Thanks @Centril. I'm not sure where that 8% regression is coming from. It doesn't appear we've added any significant work.

I did notice though that we only ever call SlowQueryLogger::query, but we should be calling SlowQueryLogger::subscription in eval and SlowQueryLogger::incremental_updates in eval_incr. Could you make those changes here? It should only be two lines.

crates/core/src/util/slow.rs Outdated Show resolved Hide resolved
crates/core/src/util/slow.rs Outdated Show resolved Hide resolved
@Centril
Copy link
Contributor Author

Centril commented Apr 18, 2024

So I commented out slow_query.log(); and replaced it with black_box(slow_query). This reduces the regression to about 5%. Further commenting out let slow_query = SlowQueryLogger::incremental_updates(ctx, sql); makes the regression go away.

@Centril Centril enabled auto-merge April 18, 2024 21:26
@Centril Centril added this pull request to the merge queue Apr 18, 2024
Merged via the queue into master with commit ce7d9b0 Apr 18, 2024
6 checks passed
@Centril Centril deleted the centril/slow-query-incr-select branch April 19, 2024 06:43
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