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

fix: reduce lock contention in distributor channels #10026

Merged
merged 3 commits into from
Apr 25, 2024

Conversation

crepererum
Copy link
Contributor

@crepererum crepererum commented Apr 10, 2024

Which issue does this PR close?

-

Rationale for this change

Reduce lock contention in distributor channels. Found while investigating runtime performance using tokio2chrome (eBPF version).

What changes are included in this PR?

  • use atomic counters instead of "counter behind mutex" where appropriate
  • use less state
  • only lock when needed
  • move "wake" operation out of lock scopes (they are eventual operations anyways and many wake operations results in "futex wake" operations -- i.e. a syscall -- which you should avoid while holding the lock)

Are these changes tested?

Existing tests pass. Benchmark didn't detect a regression.

Are there any user-facing changes?

Faster DataFusion.

Reduce lock contention in distributor channels via:

- use atomic counters instead of "counter behind mutex" where
  appropriate
- use less state
- only lock when needed
- move "wake" operation out of lock scopes (they are eventual operations
  anyways and many wake operations results in "futex wake" operations --
  i.e. a syscall -- which you should avoid while holding the lock)
@crepererum
Copy link
Contributor Author

/benchmark

Copy link

Benchmark results

Benchmarks comparing 5820507 (main) and b0f2504 (PR)
Comparing 5820507 and b0f2504
--------------------
Benchmark tpch_mem_sf1.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━━━━━━┓
┃ Query        ┃  5820507 ┃  b0f2504 ┃        Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━━━━━━┩
│ QQuery 1     │ 290.09ms │ 291.48ms │     no change │
│ QQuery 2     │  45.85ms │  44.09ms │     no change │
│ QQuery 3     │  60.33ms │  61.35ms │     no change │
│ QQuery 4     │  82.33ms │  86.86ms │  1.05x slower │
│ QQuery 5     │  99.78ms │ 104.73ms │     no change │
│ QQuery 6     │  16.27ms │  16.45ms │     no change │
│ QQuery 7     │ 223.82ms │ 234.01ms │     no change │
│ QQuery 8     │  48.31ms │  44.83ms │ +1.08x faster │
│ QQuery 9     │ 125.31ms │ 131.42ms │     no change │
│ QQuery 10    │ 111.35ms │ 117.38ms │  1.05x slower │
│ QQuery 11    │  51.73ms │  47.77ms │ +1.08x faster │
│ QQuery 12    │  59.56ms │  59.89ms │     no change │
│ QQuery 13    │ 111.92ms │ 108.55ms │     no change │
│ QQuery 14    │  19.94ms │  19.57ms │     no change │
│ QQuery 15    │  32.64ms │  33.48ms │     no change │
│ QQuery 16    │  46.17ms │  49.32ms │  1.07x slower │
│ QQuery 17    │ 158.69ms │ 163.73ms │     no change │
│ QQuery 18    │ 580.80ms │ 564.49ms │     no change │
│ QQuery 19    │  62.65ms │  63.46ms │     no change │
│ QQuery 20    │ 121.88ms │ 122.37ms │     no change │
│ QQuery 21    │ 330.63ms │ 339.71ms │     no change │
│ QQuery 22    │  39.63ms │  40.43ms │     no change │
└──────────────┴──────────┴──────────┴───────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Benchmark Summary      ┃           ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ Total Time (5820507)   │ 2719.68ms │
│ Total Time (b0f2504)   │ 2745.35ms │
│ Average Time (5820507) │  123.62ms │
│ Average Time (b0f2504) │  124.79ms │
│ Queries Faster         │         2 │
│ Queries Slower         │         3 │
│ Queries with No Change │        17 │
└────────────────────────┴───────────┘
--------------------
Benchmark tpch_sf1.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━━━━━┓
┃ Query        ┃  5820507 ┃  b0f2504 ┃       Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━━━━━┩
│ QQuery 1     │ 436.60ms │ 432.07ms │    no change │
│ QQuery 2     │  58.06ms │  60.84ms │    no change │
│ QQuery 3     │ 144.07ms │ 146.18ms │    no change │
│ QQuery 4     │  89.50ms │  89.42ms │    no change │
│ QQuery 5     │ 209.08ms │ 207.04ms │    no change │
│ QQuery 6     │ 110.04ms │ 106.89ms │    no change │
│ QQuery 7     │ 285.78ms │ 307.35ms │ 1.08x slower │
│ QQuery 8     │ 193.06ms │ 192.57ms │    no change │
│ QQuery 9     │ 288.60ms │ 295.15ms │    no change │
│ QQuery 10    │ 239.70ms │ 238.35ms │    no change │
│ QQuery 11    │  64.18ms │  64.65ms │    no change │
│ QQuery 12    │ 127.41ms │ 125.58ms │    no change │
│ QQuery 13    │ 190.93ms │ 184.27ms │    no change │
│ QQuery 14    │ 130.56ms │ 129.52ms │    no change │
│ QQuery 15    │ 192.26ms │ 191.05ms │    no change │
│ QQuery 16    │  51.36ms │  51.97ms │    no change │
│ QQuery 17    │ 320.37ms │ 331.08ms │    no change │
│ QQuery 18    │ 469.64ms │ 478.91ms │    no change │
│ QQuery 19    │ 234.30ms │ 230.49ms │    no change │
│ QQuery 20    │ 210.35ms │ 210.30ms │    no change │
│ QQuery 21    │ 331.55ms │ 331.78ms │    no change │
│ QQuery 22    │  53.64ms │  54.89ms │    no change │
└──────────────┴──────────┴──────────┴──────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Benchmark Summary      ┃           ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ Total Time (5820507)   │ 4431.05ms │
│ Total Time (b0f2504)   │ 4460.35ms │
│ Average Time (5820507) │  201.41ms │
│ Average Time (b0f2504) │  202.74ms │
│ Queries Faster         │         0 │
│ Queries Slower         │         1 │
│ Queries with No Change │        21 │
└────────────────────────┴───────────┘
--------------------
Benchmark tpch_sf10.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━┳━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Query        ┃   5820507 ┃   b0f2504 ┃    Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━╇━━━━━━━━━━━╇━━━━━━━━━━━┩
│ QQuery 1     │ 4274.48ms │ 4211.97ms │ no change │
│ QQuery 2     │  499.91ms │  513.34ms │ no change │
│ QQuery 3     │ 1722.25ms │ 1712.32ms │ no change │
│ QQuery 4     │  827.54ms │  829.91ms │ no change │
│ QQuery 5     │ 2219.89ms │ 2173.06ms │ no change │
│ QQuery 6     │ 1038.59ms │ 1011.81ms │ no change │
│ QQuery 7     │ 3660.18ms │ 3743.95ms │ no change │
│ QQuery 8     │ 2490.07ms │ 2467.25ms │ no change │
│ QQuery 9     │ 4104.66ms │ 4049.50ms │ no change │
│ QQuery 10    │ 2561.57ms │ 2549.06ms │ no change │
│ QQuery 11    │  567.74ms │  572.39ms │ no change │
│ QQuery 12    │ 1208.59ms │ 1210.43ms │ no change │
│ QQuery 13    │ 2402.98ms │ 2437.10ms │ no change │
│ QQuery 14    │ 1298.24ms │ 1261.79ms │ no change │
│ QQuery 15    │ 1991.00ms │ 1936.49ms │ no change │
│ QQuery 16    │  528.45ms │  527.79ms │ no change │
│ QQuery 17    │ 5412.60ms │ 5406.55ms │ no change │
│ QQuery 18    │ 7067.26ms │ 7042.52ms │ no change │
│ QQuery 19    │ 2262.75ms │ 2237.31ms │ no change │
│ QQuery 20    │ 2602.28ms │ 2656.07ms │ no change │
│ QQuery 21    │ 4497.38ms │ 4544.22ms │ no change │
│ QQuery 22    │  569.89ms │  588.53ms │ no change │
└──────────────┴───────────┴───────────┴───────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━┓
┃ Benchmark Summary      ┃            ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━┩
│ Total Time (5820507)   │ 53808.31ms │
│ Total Time (b0f2504)   │ 53683.35ms │
│ Average Time (5820507) │  2445.83ms │
│ Average Time (b0f2504) │  2440.15ms │
│ Queries Faster         │          0 │
│ Queries Slower         │          0 │
│ Queries with No Change │         22 │
└────────────────────────┴────────────┘

@crepererum
Copy link
Contributor Author

/benchmark

Copy link

Benchmark results

Benchmarks comparing 03d8ba1 (main) and b0f2504 (PR)
Comparing 03d8ba1 and b0f2504
--------------------
Benchmark tpch_mem_sf1.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━━━━━━┓
┃ Query        ┃  03d8ba1 ┃  b0f2504 ┃        Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━━━━━━┩
│ QQuery 1     │ 292.63ms │ 291.45ms │     no change │
│ QQuery 2     │  41.74ms │  44.07ms │  1.06x slower │
│ QQuery 3     │  60.75ms │  62.66ms │     no change │
│ QQuery 4     │  80.09ms │  87.89ms │  1.10x slower │
│ QQuery 5     │ 103.26ms │ 104.92ms │     no change │
│ QQuery 6     │  16.24ms │  16.34ms │     no change │
│ QQuery 7     │ 224.37ms │ 246.22ms │  1.10x slower │
│ QQuery 8     │  51.63ms │  44.11ms │ +1.17x faster │
│ QQuery 9     │ 122.66ms │ 123.21ms │     no change │
│ QQuery 10    │ 109.04ms │ 112.72ms │     no change │
│ QQuery 11    │  49.43ms │  50.62ms │     no change │
│ QQuery 12    │  59.56ms │  59.95ms │     no change │
│ QQuery 13    │ 117.39ms │ 112.65ms │     no change │
│ QQuery 14    │  20.05ms │  19.66ms │     no change │
│ QQuery 15    │  32.63ms │  32.95ms │     no change │
│ QQuery 16    │  48.37ms │  49.44ms │     no change │
│ QQuery 17    │ 181.50ms │ 172.49ms │     no change │
│ QQuery 18    │ 514.65ms │ 552.57ms │  1.07x slower │
│ QQuery 19    │  62.34ms │  63.28ms │     no change │
│ QQuery 20    │ 127.62ms │ 128.55ms │     no change │
│ QQuery 21    │ 371.02ms │ 386.07ms │     no change │
│ QQuery 22    │  39.74ms │  40.11ms │     no change │
└──────────────┴──────────┴──────────┴───────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Benchmark Summary      ┃           ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ Total Time (03d8ba1)   │ 2726.71ms │
│ Total Time (b0f2504)   │ 2801.95ms │
│ Average Time (03d8ba1) │  123.94ms │
│ Average Time (b0f2504) │  127.36ms │
│ Queries Faster         │         1 │
│ Queries Slower         │         4 │
│ Queries with No Change │        17 │
└────────────────────────┴───────────┘
--------------------
Benchmark tpch_sf1.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━┳━━━━━━━━━━━━━━━┓
┃ Query        ┃  03d8ba1 ┃  b0f2504 ┃        Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━╇━━━━━━━━━━━━━━━┩
│ QQuery 1     │ 435.45ms │ 436.63ms │     no change │
│ QQuery 2     │  57.51ms │  59.13ms │     no change │
│ QQuery 3     │ 144.73ms │ 144.56ms │     no change │
│ QQuery 4     │  88.92ms │  89.96ms │     no change │
│ QQuery 5     │ 202.77ms │ 205.96ms │     no change │
│ QQuery 6     │ 108.45ms │ 105.62ms │     no change │
│ QQuery 7     │ 281.53ms │ 303.99ms │  1.08x slower │
│ QQuery 8     │ 189.14ms │ 192.36ms │     no change │
│ QQuery 9     │ 288.18ms │ 305.40ms │  1.06x slower │
│ QQuery 10    │ 232.11ms │ 233.84ms │     no change │
│ QQuery 11    │  64.18ms │  64.28ms │     no change │
│ QQuery 12    │ 125.82ms │ 126.93ms │     no change │
│ QQuery 13    │ 184.80ms │ 187.32ms │     no change │
│ QQuery 14    │ 128.78ms │ 124.91ms │     no change │
│ QQuery 15    │ 190.63ms │ 186.12ms │     no change │
│ QQuery 16    │  51.00ms │  50.58ms │     no change │
│ QQuery 17    │ 338.74ms │ 314.73ms │ +1.08x faster │
│ QQuery 18    │ 474.30ms │ 457.53ms │     no change │
│ QQuery 19    │ 230.47ms │ 227.16ms │     no change │
│ QQuery 20    │ 194.03ms │ 203.42ms │     no change │
│ QQuery 21    │ 327.99ms │ 334.56ms │     no change │
│ QQuery 22    │  53.91ms │  53.32ms │     no change │
└──────────────┴──────────┴──────────┴───────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Benchmark Summary      ┃           ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ Total Time (03d8ba1)   │ 4393.47ms │
│ Total Time (b0f2504)   │ 4408.31ms │
│ Average Time (03d8ba1) │  199.70ms │
│ Average Time (b0f2504) │  200.38ms │
│ Queries Faster         │         1 │
│ Queries Slower         │         2 │
│ Queries with No Change │        19 │
└────────────────────────┴───────────┘
--------------------
Benchmark tpch_sf10.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━┳━━━━━━━━━━━┳━━━━━━━━━━━━━━━┓
┃ Query        ┃   03d8ba1 ┃   b0f2504 ┃        Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━╇━━━━━━━━━━━╇━━━━━━━━━━━━━━━┩
│ QQuery 1     │ 4297.05ms │ 4184.31ms │     no change │
│ QQuery 2     │  529.93ms │  503.29ms │ +1.05x faster │
│ QQuery 3     │ 1741.97ms │ 1712.23ms │     no change │
│ QQuery 4     │  835.57ms │  820.64ms │     no change │
│ QQuery 5     │ 2298.59ms │ 2196.33ms │     no change │
│ QQuery 6     │ 1055.47ms │ 1012.67ms │     no change │
│ QQuery 7     │ 3810.43ms │ 3664.84ms │     no change │
│ QQuery 8     │ 2558.10ms │ 2436.67ms │     no change │
│ QQuery 9     │ 4242.98ms │ 4031.18ms │     no change │
│ QQuery 10    │ 2613.70ms │ 2501.35ms │     no change │
│ QQuery 11    │  590.84ms │  582.21ms │     no change │
│ QQuery 12    │ 1207.89ms │ 1223.83ms │     no change │
│ QQuery 13    │ 2427.26ms │ 2391.60ms │     no change │
│ QQuery 14    │ 1310.94ms │ 1271.25ms │     no change │
│ QQuery 15    │ 2031.25ms │ 1937.52ms │     no change │
│ QQuery 16    │  529.06ms │  534.78ms │     no change │
│ QQuery 17    │ 5497.43ms │ 5337.07ms │     no change │
│ QQuery 18    │ 7229.58ms │ 6996.20ms │     no change │
│ QQuery 19    │ 2287.99ms │ 2240.86ms │     no change │
│ QQuery 20    │ 2593.12ms │ 2605.52ms │     no change │
│ QQuery 21    │ 4696.34ms │ 4345.08ms │ +1.08x faster │
│ QQuery 22    │  594.11ms │  566.70ms │     no change │
└──────────────┴───────────┴───────────┴───────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━┓
┃ Benchmark Summary      ┃            ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━┩
│ Total Time (03d8ba1)   │ 54979.61ms │
│ Total Time (b0f2504)   │ 53096.12ms │
│ Average Time (03d8ba1) │  2499.07ms │
│ Average Time (b0f2504) │  2413.46ms │
│ Queries Faster         │          2 │
│ Queries Slower         │          0 │
│ Queries with No Change │         20 │
└────────────────────────┴────────────┘

@crepererum
Copy link
Contributor Author

crepererum commented Apr 11, 2024

Benchmarks are mostly noise, but locally in a server-like setting with multiple consumers and a limited number of tokio threads, I can totally see both a reduces lock contention (based on futex-waits) and higher performance.

@crepererum crepererum marked this pull request as ready for review April 11, 2024 08:46
Dandandan
Dandandan previously approved these changes Apr 11, 2024
Copy link
Contributor

@Dandandan Dandandan left a comment

Choose a reason for hiding this comment

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

LGTM. I wonder if benchmarks show a difference on higher cpu count (instead of GH runners)?

@alamb alamb changed the title fix: lock contention in distributor channels fix: reduce lock contention in distributor channels Apr 11, 2024
@alamb
Copy link
Contributor

alamb commented Apr 11, 2024

LGTM. I wonder if benchmarks show a difference on higher cpu count (instead of GH runners)?

I will run them on my 8 core benchmark machine to see if I see a difference

alamb
alamb previously approved these changes Apr 11, 2024
Copy link
Contributor

@alamb alamb left a comment

Choose a reason for hiding this comment

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

Looks good to me, thank you @crepererum and @Dandandan

I read the code carefully, and I think it looks good, though there is one area related to a potential race condition that I think would be worth reviewing

Also, given the trickiness of this code (with several inter-related mutexes) I think encapsulating the functionality into methods on Channel / ChannelState would make the flow easier to follow and verify. However, this is a personal preference and I don't think it is required.

I'll post my performance results here when I have them


// does ANY receiver need data?
// if so, allow sender to create another
if this.gate.empty_channels.load(Ordering::SeqCst) == 0 {
Copy link
Contributor

Choose a reason for hiding this comment

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

Is accessing this field before taking the send_wakers a race condition?

I think the answer is no, as self.channel.state.lock() is preventing empty_channels from changing between this line and the guard

However, if this is the case wouldn't it be clearer to not use an atomic usize here and just hang the count on channel state?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

However, if this is the case wouldn't it be clearer to not use an atomic usize here and just hang the count on channel state?

Reading this size should be cheap (=lockless). If you place that behind a mutex, all threads will have a single hot-spot critical section.

n_senders: 1,
recv_alive: true,
recv_wakers: Vec::default(),
Arc::new(Channel {
Copy link
Contributor

Choose a reason for hiding this comment

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

It would help me with readability / encapsulation to make this Channel::new() or Channel::default() so it is easier to follow the locking logic

Comment on lines 235 to 241
let to_wake = guard_channel_state
.recv_wakers
.as_mut()
.expect("not closed");
let mut tmp = Vec::with_capacity(to_wake.capacity());
std::mem::swap(to_wake, &mut tmp);
tmp
Copy link
Contributor

Choose a reason for hiding this comment

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

This might be more readable if it was in a function like

guard_channel_state.take_wakers()

Or something - that would also give you a place to document what was happening more

Comment on lines +171 to +175
if state
.data
.as_ref()
.map(|data| data.is_empty())
.unwrap_or_default()
Copy link
Contributor

Choose a reason for hiding this comment

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

Could we put this into ChannelState as a function with a more readable name? Like

if state.channel_gone() {
...

@alamb
Copy link
Contributor

alamb commented Apr 11, 2024

Benchmark results. The only one that looks potentially problematic is clickbench 28 -- I'll rerun and see if I can reproduce the results

│ QQuery 28    │ 27356.53ms │               30720.69ms │ 1.12x slower │
--------------------
Benchmark tpch_mem.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━┓
┃ Query        ┃ main_base ┃ crepererum_fix_locking_2 ┃        Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━┩
│ QQuery 1     │  208.16ms │                 202.92ms │     no change │
│ QQuery 2     │   39.25ms │                  41.98ms │  1.07x slower │
│ QQuery 3     │   61.22ms │                  62.78ms │     no change │
│ QQuery 4     │   61.86ms │                  59.45ms │     no change │
│ QQuery 5     │   97.23ms │                  94.53ms │     no change │
│ QQuery 6     │   15.03ms │                  14.61ms │     no change │
│ QQuery 7     │  194.63ms │                 200.19ms │     no change │
│ QQuery 8     │   42.67ms │                  41.67ms │     no change │
│ QQuery 9     │  112.37ms │                 109.34ms │     no change │
│ QQuery 10    │  105.84ms │                 102.00ms │     no change │
│ QQuery 11    │   35.28ms │                  35.14ms │     no change │
│ QQuery 12    │   49.17ms │                  47.43ms │     no change │
│ QQuery 13    │   80.66ms │                  76.34ms │ +1.06x faster │
│ QQuery 14    │   19.90ms │                  20.74ms │     no change │
│ QQuery 15    │   33.05ms │                  33.46ms │     no change │
│ QQuery 16    │   42.43ms │                  40.60ms │     no change │
│ QQuery 17    │  153.25ms │                 152.00ms │     no change │
│ QQuery 18    │  435.15ms │                 427.61ms │     no change │
│ QQuery 19    │   51.48ms │                  49.68ms │     no change │
│ QQuery 20    │   91.23ms │                  95.71ms │     no change │
│ QQuery 21    │  278.06ms │                 263.75ms │ +1.05x faster │
│ QQuery 22    │   28.81ms │                  29.54ms │     no change │
└──────────────┴───────────┴──────────────────────────┴───────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Benchmark Summary                       ┃           ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ Total Time (main_base)                  │ 2236.74ms │
│ Total Time (crepererum_fix_locking_2)   │ 2201.51ms │
│ Average Time (main_base)                │  101.67ms │
│ Average Time (crepererum_fix_locking_2) │  100.07ms │
│ Queries Faster                          │         2 │
│ Queries Slower                          │         1 │
│ Queries with No Change                  │        19 │
└─────────────────────────────────────────┴───────────┘
--------------------
Benchmark tpch.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┓
┃ Query        ┃ main_base ┃ crepererum_fix_locking_2 ┃       Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━┩
│ QQuery 1     │  329.78ms │                 341.28ms │    no change │
│ QQuery 2     │  128.45ms │                 129.32ms │    no change │
│ QQuery 3     │  158.71ms │                 167.35ms │ 1.05x slower │
│ QQuery 4     │   96.10ms │                 101.48ms │ 1.06x slower │
│ QQuery 5     │  195.68ms │                 196.14ms │    no change │
│ QQuery 6     │   87.22ms │                  91.13ms │    no change │
│ QQuery 7     │  276.19ms │                 283.92ms │    no change │
│ QQuery 8     │  202.38ms │                 209.16ms │    no change │
│ QQuery 9     │  314.49ms │                 323.30ms │    no change │
│ QQuery 10    │  265.75ms │                 274.15ms │    no change │
│ QQuery 11    │  111.10ms │                 113.51ms │    no change │
│ QQuery 12    │  149.44ms │                 150.26ms │    no change │
│ QQuery 13    │  315.74ms │                 326.79ms │    no change │
│ QQuery 14    │  119.72ms │                 128.31ms │ 1.07x slower │
│ QQuery 15    │  168.98ms │                 182.46ms │ 1.08x slower │
│ QQuery 16    │  102.12ms │                 105.52ms │    no change │
│ QQuery 17    │  297.66ms │                 311.36ms │    no change │
│ QQuery 18    │  411.50ms │                 414.46ms │    no change │
│ QQuery 19    │  193.98ms │                 201.26ms │    no change │
│ QQuery 20    │  182.63ms │                 201.86ms │ 1.11x slower │
│ QQuery 21    │  339.35ms │                 337.28ms │    no change │
│ QQuery 22    │   78.99ms │                  82.41ms │    no change │
└──────────────┴───────────┴──────────────────────────┴──────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Benchmark Summary                       ┃           ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ Total Time (main_base)                  │ 4525.96ms │
│ Total Time (crepererum_fix_locking_2)   │ 4672.71ms │
│ Average Time (main_base)                │  205.73ms │
│ Average Time (crepererum_fix_locking_2) │  212.40ms │
│ Queries Faster                          │         0 │
│ Queries Slower                          │         5 │
│ Queries with No Change                  │        17 │
└─────────────────────────────────────────┴───────────┘
--------------------
Benchmark clickbench_extended.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Query        ┃ main_base ┃ crepererum_fix_locking_2 ┃    Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ QQuery 0     │ 3518.76ms │                3464.59ms │ no change │
│ QQuery 1     │ 1359.44ms │                1318.98ms │ no change │
│ QQuery 2     │ 2765.57ms │                2793.54ms │ no change │
└──────────────┴───────────┴──────────────────────────┴───────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━┓
┃ Benchmark Summary                       ┃           ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━┩
│ Total Time (main_base)                  │ 7643.77ms │
│ Total Time (crepererum_fix_locking_2)   │ 7577.11ms │
│ Average Time (main_base)                │ 2547.92ms │
│ Average Time (crepererum_fix_locking_2) │ 2525.70ms │
│ Queries Faster                          │         0 │
│ Queries Slower                          │         0 │
│ Queries with No Change                  │         3 │
└─────────────────────────────────────────┴───────────┘
--------------------
Benchmark clickbench_1.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┓
┃ Query        ┃  main_base ┃ crepererum_fix_locking_2 ┃       Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━┩
│ QQuery 0     │     0.88ms │                   0.91ms │    no change │
│ QQuery 1     │    89.09ms │                  91.25ms │    no change │
│ QQuery 2     │   199.69ms │                 197.63ms │    no change │
│ QQuery 3     │   194.73ms │                 203.30ms │    no change │
│ QQuery 4     │  2093.75ms │                2062.80ms │    no change │
│ QQuery 5     │  1952.25ms │                1902.11ms │    no change │
│ QQuery 6     │    82.19ms │                  78.71ms │    no change │
│ QQuery 7     │    92.88ms │                  94.01ms │    no change │
│ QQuery 8     │  3074.62ms │                3178.68ms │    no change │
│ QQuery 9     │  2327.77ms │                2308.59ms │    no change │
│ QQuery 10    │   780.46ms │                 796.81ms │    no change │
│ QQuery 11    │   848.76ms │                 864.63ms │    no change │
│ QQuery 12    │  2048.46ms │                2035.28ms │    no change │
│ QQuery 13    │  4364.39ms │                4289.92ms │    no change │
│ QQuery 14    │  2719.47ms │                2743.64ms │    no change │
│ QQuery 15    │  2354.00ms │                2321.72ms │    no change │
│ QQuery 16    │  5522.06ms │                5530.26ms │    no change │
│ QQuery 17    │  5463.80ms │                5494.81ms │    no change │
│ QQuery 18    │ 11140.18ms │               10973.02ms │    no change │
│ QQuery 19    │   161.06ms │                 164.70ms │    no change │
│ QQuery 20    │  2609.20ms │                2589.19ms │    no change │
│ QQuery 21    │  3326.62ms │                3326.95ms │    no change │
│ QQuery 22    │  9043.88ms │                9020.46ms │    no change │
│ QQuery 23    │ 20855.10ms │               20686.94ms │    no change │
│ QQuery 24    │  1329.66ms │                1297.87ms │    no change │
│ QQuery 25    │  1132.55ms │                1117.24ms │    no change │
│ QQuery 26    │  1453.63ms │                1418.42ms │    no change │
│ QQuery 27    │  3845.14ms │                3758.03ms │    no change │
│ QQuery 28    │ 27356.53ms │               30720.69ms │ 1.12x slower │
│ QQuery 29    │  1082.37ms │                1059.70ms │    no change │
│ QQuery 30    │  2415.60ms │                2330.50ms │    no change │
│ QQuery 31    │  3102.71ms │                3013.29ms │    no change │
│ QQuery 32    │ 15520.66ms │               15396.94ms │    no change │
│ QQuery 33    │  8968.94ms │                8908.69ms │    no change │
│ QQuery 34    │ 13112.15ms │               13167.68ms │    no change │
│ QQuery 35    │  3807.04ms │                3731.88ms │    no change │
│ QQuery 36    │   338.47ms │                 334.33ms │    no change │
│ QQuery 37    │   226.46ms │                 229.11ms │    no change │
│ QQuery 38    │   190.78ms │                 188.71ms │    no change │
│ QQuery 39    │  1103.90ms │                1091.60ms │    no change │
│ QQuery 40    │    91.35ms │                  90.12ms │    no change │
│ QQuery 41    │    83.58ms │                  82.36ms │    no change │
│ QQuery 42    │    98.58ms │                  98.17ms │    no change │
└──────────────┴────────────┴──────────────────────────┴──────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━┓
┃ Benchmark Summary                       ┃             ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━┩
│ Total Time (main_base)                  │ 166605.39ms │
│ Total Time (crepererum_fix_locking_2)   │ 168991.63ms │
│ Average Time (main_base)                │   3874.54ms │
│ Average Time (crepererum_fix_locking_2) │   3930.04ms │
│ Queries Faster                          │           0 │
│ Queries Slower                          │           1 │
│ Queries with No Change                  │          42 │
└─────────────────────────────────────────┴─────────────┘

@alamb
Copy link
Contributor

alamb commented Apr 11, 2024

🤔 it seems like q28 is really quite a bit slower

--------------------
Benchmark clickbench_1.json
--------------------z
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┓
┃ Query        ┃  main_base ┃ crepererum_fix_locking_2 ┃       Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━┩
│ QQuery 0     │     0.88ms │                   0.88ms │    no change │
│ QQuery 1     │    90.28ms │                  89.78ms │    no change │
│ QQuery 2     │   200.16ms │                 197.66ms │    no change │
│ QQuery 3     │   193.44ms │                 200.52ms │    no change │
│ QQuery 4     │  2126.91ms │                2096.56ms │    no change │
│ QQuery 5     │  1938.93ms │                1921.88ms │    no change │
│ QQuery 6     │    81.04ms │                  79.62ms │    no change │
│ QQuery 7     │    94.22ms │                  92.97ms │    no change │
│ QQuery 8     │  3154.20ms │                3170.60ms │    no change │
│ QQuery 9     │  2333.97ms │                2286.43ms │    no change │
│ QQuery 10    │   787.01ms │                 786.79ms │    no change │
│ QQuery 11    │   868.96ms │                 866.20ms │    no change │
│ QQuery 12    │  2058.44ms │                2050.60ms │    no change │
│ QQuery 13    │  4383.03ms │                4367.34ms │    no change │
│ QQuery 14    │  2754.36ms │                2767.70ms │    no change │
│ QQuery 15    │  2345.20ms │                2346.56ms │    no change │
│ QQuery 16    │  5698.70ms │                5628.87ms │    no change │
│ QQuery 17    │  5538.73ms │                5553.24ms │    no change │
│ QQuery 18    │ 11312.88ms │               11265.56ms │    no change │
│ QQuery 19    │   163.65ms │                 167.57ms │    no change │
│ QQuery 20    │  2605.45ms │                2621.66ms │    no change │
│ QQuery 21    │  3365.08ms │                3362.64ms │    no change │
│ QQuery 22    │  9104.27ms │                9041.65ms │    no change │
│ QQuery 23    │ 20984.24ms │               21005.52ms │    no change │
│ QQuery 24    │  1309.36ms │                1341.46ms │    no change │
│ QQuery 25    │  1124.85ms │                1142.49ms │    no change │
│ QQuery 26    │  1461.67ms │                1463.87ms │    no change │
│ QQuery 27    │  3838.62ms │                3833.38ms │    no change │
│ QQuery 28    │ 27503.66ms │               31028.45ms │ 1.13x slower │
│ QQuery 29    │  1079.65ms │                1061.61ms │    no change │
│ QQuery 30    │  2442.00ms │                2458.44ms │    no change │
│ QQuery 31    │  3158.01ms │                3148.10ms │    no change │
│ QQuery 32    │ 15667.35ms │               15816.11ms │    no change │
│ QQuery 33    │  8918.74ms │                9045.33ms │    no change │
│ QQuery 34    │ 13258.82ms │               13317.26ms │    no change │
│ QQuery 35    │  3837.79ms │                3796.75ms │    no change │
│ QQuery 36    │   334.39ms │                 336.88ms │    no change │
│ QQuery 37    │   230.24ms │                 228.43ms │    no change │
│ QQuery 38    │   188.37ms │                 191.81ms │    no change │
│ QQuery 39    │  1107.22ms │                1093.84ms │    no change │
│ QQuery 40    │    90.00ms │                  89.63ms │    no change │
│ QQuery 41    │    83.82ms │                  82.48ms │    no change │
│ QQuery 42    │    98.11ms │                  99.87ms │    no change │
└──────────────┴────────────┴──────────────────────────┴──────────────┘

@alamb alamb dismissed their stale review April 11, 2024 15:08

We need to investigate the performance regression

@Dandandan Dandandan self-requested a review April 12, 2024 06:35
@Dandandan Dandandan dismissed their stale review April 12, 2024 06:36

performance regression

@crepererum
Copy link
Contributor Author

crepererum commented Apr 12, 2024

I've pushed another change that makes the code prettier and also fixes a potential "Time-of-check to time-of-use" race condition.

With that, I disagree on benchmark results:

┏━━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━┓
┃ Query        ┃       HEAD ┃ crepererum_fix_locking_2 ┃        Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━┩
│ QQuery 0     │     1.88ms │                   1.65ms │ +1.14x faster │
│ QQuery 1     │   148.18ms │                 140.00ms │ +1.06x faster │
│ QQuery 2     │   241.73ms │                 245.93ms │     no change │
│ QQuery 3     │   211.72ms │                 215.69ms │     no change │
│ QQuery 4     │  1126.35ms │                1092.26ms │     no change │
│ QQuery 5     │  1626.14ms │                1597.87ms │     no change │
│ QQuery 6     │   133.90ms │                 127.97ms │     no change │
│ QQuery 7     │   144.12ms │                 142.77ms │     no change │
│ QQuery 8     │  2110.61ms │                2110.96ms │     no change │
│ QQuery 9     │  1961.65ms │                1974.22ms │     no change │
│ QQuery 10    │   849.43ms │                 858.37ms │     no change │
│ QQuery 11    │   924.44ms │                 933.75ms │     no change │
│ QQuery 12    │  1824.36ms │                1771.39ms │     no change │
│ QQuery 13    │  3558.95ms │                3440.59ms │     no change │
│ QQuery 14    │  2464.64ms │                2432.15ms │     no change │
│ QQuery 15    │  1357.67ms │                1344.27ms │     no change │
│ QQuery 16    │  4341.64ms │                4152.79ms │     no change │
│ QQuery 17    │  4187.07ms │                4063.80ms │     no change │
│ QQuery 18    │  8574.30ms │                8029.32ms │ +1.07x faster │
│ QQuery 19    │   214.11ms │                 209.38ms │     no change │
│ QQuery 20    │  2853.35ms │                2853.49ms │     no change │
│ QQuery 21    │  3490.41ms │                3496.37ms │     no change │
│ QQuery 22    │  8822.14ms │                8858.85ms │     no change │
│ QQuery 23    │ 18285.30ms │               18143.82ms │     no change │
│ QQuery 24    │  1395.89ms │                1359.07ms │     no change │
│ QQuery 25    │  1267.17ms │                1298.45ms │     no change │
│ QQuery 26    │  1504.78ms │                1473.00ms │     no change │
│ QQuery 27    │  4016.63ms │                3987.70ms │     no change │
│ QQuery 28    │ 26548.72ms │               26645.04ms │     no change │
│ QQuery 29    │  1256.12ms │                1252.63ms │     no change │
│ QQuery 30    │  2108.74ms │                2122.03ms │     no change │
│ QQuery 31    │  2611.22ms │                2648.77ms │     no change │
│ QQuery 32    │ 10823.03ms │               10513.90ms │     no change │
│ QQuery 33    │  7044.21ms │                6793.15ms │     no change │
│ QQuery 34    │ 10667.37ms │               10355.54ms │     no change │
│ QQuery 35    │  2730.23ms │                2795.33ms │     no change │
│ QQuery 36    │   560.60ms │                 585.77ms │     no change │
│ QQuery 37    │   443.45ms │                 436.09ms │     no change │
│ QQuery 38    │   363.35ms │                 381.37ms │     no change │
│ QQuery 39    │  1476.39ms │                1644.64ms │  1.11x slower │
│ QQuery 40    │   155.80ms │                 165.54ms │  1.06x slower │
│ QQuery 41    │   150.92ms │                 151.93ms │     no change │
│ QQuery 42    │   175.61ms │                 181.80ms │     no change │
└──────────────┴────────────┴──────────────────────────┴───────────────┘
┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━┓
┃ Benchmark Summary                       ┃             ┃
┡━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━┩
│ Total Time (HEAD)                       │ 144754.34ms │
│ Total Time (crepererum_fix_locking_2)   │ 143029.41ms │
│ Average Time (HEAD)                     │   3366.38ms │
│ Average Time (crepererum_fix_locking_2) │   3326.27ms │
│ Queries Faster                          │           3 │
│ Queries Slower                          │           2 │
│ Queries with No Change                  │          38 │
└─────────────────────────────────────────┴─────────────┘

Or in other words: I think it's noise.

You may wonder why my perf results are so bad: I'm testing on a Laptop but locked the frequency down to 1.5GHz to avoid thermal throttling, otherwise the numbers would be all over the place (and would also depend on previous runs, uptime and other factors too much).

@alamb
Copy link
Contributor

alamb commented Apr 12, 2024

Or in other words: I think it's noise.

Thanks @crepererum -- I am rerunning on my test machine (a VM on gcp)

@alamb
Copy link
Contributor

alamb commented Apr 12, 2024

In case anyone is interested, here is q28:

SELECT
  REGEXP_REPLACE("Referer", '^https?://(?:www\\.)?([^/]+)/.*$', '\\1') AS k,
  AVG(length("Referer")) AS l,
  COUNT(*) AS c,
  MIN("Referer")
FROM 'hits.parquet'
WHERE "Referer" <> ''
GROUP BY k
HAVING COUNT(*) > 100000
ORDER BY l DESC
LIMIT 25;

My unscientific run on my laptop without control also showed no difference with the current ode

However, when I ran on my 8 core (relatively old) GCP VM I still see the difference. I am now trying to reproduce standalone and will profile

Benchmark clickbench_1.json
--------------------
┏━━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━┓
┃ Query        ┃  main_base ┃ crepererum_fix_locking_2 ┃        Change ┃
┡━━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━┩
│ QQuery 0     │     0.87ms │                   0.87ms │     no change │
│ QQuery 1     │    91.74ms │                  89.61ms │     no change │
│ QQuery 2     │   202.25ms │                 188.96ms │ +1.07x faster │
│ QQuery 3     │   203.15ms │                 201.24ms │     no change │
│ QQuery 4     │  2178.08ms │                2133.03ms │     no change │
│ QQuery 5     │  1978.68ms │                1946.31ms │     no change │
│ QQuery 6     │    82.22ms │                  78.83ms │     no change │
│ QQuery 7     │    93.84ms │                  94.38ms │     no change │
│ QQuery 8     │  3230.17ms │                3163.31ms │     no change │
│ QQuery 9     │  2360.81ms │                2331.88ms │     no change │
│ QQuery 10    │   790.32ms │                 795.43ms │     no change │
│ QQuery 11    │   866.96ms │                 873.08ms │     no change │
│ QQuery 12    │  2088.24ms │                2038.80ms │     no change │
│ QQuery 13    │  4529.64ms │                4404.47ms │     no change │
│ QQuery 14    │  2811.68ms │                2765.81ms │     no change │
│ QQuery 15    │  2408.97ms │                2378.54ms │     no change │
│ QQuery 16    │  5780.20ms │                5703.77ms │     no change │
│ QQuery 17    │  5668.54ms │                5681.91ms │     no change │
│ QQuery 18    │ 11792.67ms │               11618.15ms │     no change │
│ QQuery 19    │   169.77ms │                 163.61ms │     no change │
│ QQuery 20    │  2623.55ms │                2658.90ms │     no change │
│ QQuery 21    │  3371.72ms │                3373.27ms │     no change │
│ QQuery 22    │  9206.03ms │                9128.75ms │     no change │
│ QQuery 23    │ 21139.41ms │               20945.87ms │     no change │
│ QQuery 24    │  1346.77ms │                1349.85ms │     no change │
│ QQuery 25    │  1156.21ms │                1155.25ms │     no change │
│ QQuery 26    │  1457.70ms │                1449.86ms │     no change │
│ QQuery 27    │  3887.48ms │                3902.40ms │     no change │
│ QQuery 28    │ 27623.76ms │               31083.80ms │  1.13x slower │
│ QQuery 29    │  1043.40ms │                1032.56ms │     no change │
│ QQuery 30    │  2496.35ms │                2486.42ms │     no change │
│ QQuery 31    │  3240.97ms │                3209.81ms │     no change │
│ QQuery 32    │ 16334.45ms │               16530.24ms │     no change │
│ QQuery 33    │  9369.49ms │                9258.06ms │     no change │
│ QQuery 34    │ 13848.46ms │               13797.41ms │     no change │
│ QQuery 35    │  3889.05ms │                3966.32ms │     no change │
│ QQuery 36    │   348.41ms │                 346.92ms │     no change │
│ QQuery 37    │   228.01ms │                 232.12ms │     no change │
│ QQuery 38    │   193.57ms │                 197.31ms │     no change │
│ QQuery 39    │  1130.99ms │                1138.56ms │     no change │
│ QQuery 40    │    91.47ms │                  95.42ms │     no change │
│ QQuery 41    │    82.12ms │                  80.95ms │     no change │
│ QQuery 42    │    98.66ms │                  97.82ms │     no change │
└──────────────┴────────────┴──────────────────────────┴───────────────┘

@alamb
Copy link
Contributor

alamb commented Apr 24, 2024

Sorry for the delay, I spent time trying to reproduce performance difference in this PR

Reproducer

  1. Download: https://datasets.clickhouse.com/hits_compatible/hits.parquet
  2. Use q28.sql
cat q28.sql
SELECT REGEXP_REPLACE("Referer", '^https?://(?:www\\.)?([^/]+)/.*$', '\\1') AS k, AVG(length("Referer")) AS l, COUNT(*) AS c, MIN("Referer")
FROM 'hits.parquet' WHERE "Referer" <> '' GROUP BY k HAVING COUNT(*) > 100000 ORDER BY l DESC LIMIT 25;

Tests

Build datafusion-cli with

cd datafusion-cli
cargo build --release
cp target/release/datafusion-cli ~/Downloads/datafusion-cli-distributor

Also build it with merge-base

git checkout `git merge-base HEAD apache/main`
cd datafusion-cli
cargo build --release
cp target/release/datafusion-cli ~/Downloads/datafusion-cli-merge-base
for i in `seq 1 5`; do ./datafusion-cli-distributor -f q28.sql  | grep Elapsed ; done
Elapsed 6.576 seconds.
Elapsed 6.591 seconds.
Elapsed 6.499 seconds.
Elapsed 6.599 seconds.
Elapsed 6.515 seconds.
 for i in `seq 1 5`; do ./datafusion-cli-merge-base  -f q28.sql  | grep Elapsed ; done
Elapsed 6.756 seconds.
Elapsed 6.761 seconds.
Elapsed 6.633 seconds.
Elapsed 6.565 seconds.
Elapsed 6.565 seconds.

If anything this looks better for the distributor branch.

I'll see if I can reproduce the results on the gcp machine

@crepererum
Copy link
Contributor Author

If it helps, I can rebase this PR as well.

Copy link
Contributor

@alamb alamb left a comment

Choose a reason for hiding this comment

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

I re-ran the tests manually and can't see any significant difference

alamb@aal-dev:~$ for i in `seq 1 5`; do ./datafusion-cli-merge-base  -f q28.sql  | grep Elapsed ; done
Elapsed 28.206 seconds.
Elapsed 27.259 seconds.
Elapsed 27.456 seconds.
Elapsed 27.371 seconds.
Elapsed 27.130 seconds.
alamb@aal-dev:~$ ln -s arrow-datafusion11/datafusion-cli/target/release/datafusion-cli ./datafusion-cli-distributor
ln: failed to create symbolic link './datafusion-cli-distributor': File exists
alamb@aal-dev:~$ for i in `seq 1 5`; do ./datafusion-cli-distributor -f q28.sql  | grep Elapsed ; done
Elapsed 27.382 seconds.
Elapsed 27.145 seconds.
Elapsed 27.302 seconds.
Elapsed 27.031 seconds.
Elapsed 27.338 seconds.

Thus I think we should proceed with merging this PR and we can adjust it later if needed

@alamb
Copy link
Contributor

alamb commented Apr 25, 2024

I merged this branch up from main, and plan to merge it once the CI checks pass

@alamb alamb merged commit b87f210 into apache:main Apr 25, 2024
23 checks passed
ccciudatu pushed a commit to hstack/arrow-datafusion that referenced this pull request Apr 26, 2024
* fix: lock contention in distributor channels

Reduce lock contention in distributor channels via:

- use atomic counters instead of "counter behind mutex" where
  appropriate
- use less state
- only lock when needed
- move "wake" operation out of lock scopes (they are eventual operations
  anyways and many wake operations results in "futex wake" operations --
  i.e. a syscall -- which you should avoid while holding the lock)

* refactor: add more docs and tests for distributor channels

---------

Co-authored-by: Andrew Lamb <andrew@nerdnetworks.org>
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.

None yet

3 participants