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

direct local reader for raw read #4222

Merged

Conversation

@fredchenbj
Copy link
Contributor

commented Feb 15, 2019

Signed-off-by: fredchenbj cfworking@163.com

What have you changed? (mandatory)

To reduce the latency of tikv's raw read, change the read flow "readpool->localreader->readpool" to "localreader->readpool", i.e. directly ask async_snapshot first, then pass the snapshot to readpool in the callback of async_snapshot. Thus, reduce the overhead of context switch. Under a benchmark test, context switch reduced about 15% compared to the old implementation.

Changed four funtions about raw read: async_raw_get, async_raw_batch_get, async_raw_scan and async_raw_batch_scan.

What are the type of the changes? (mandatory)

Improvement

How has this PR been tested? (mandatory)

unit tests and manual tests

Does this PR affect documentation (docs) update? (mandatory)

no

Does this PR affect tidb-ansible update? (mandatory)

no

Refer to a related PR or issue link (optional)

Benchmark result if necessary (optional)

Add a few positive/negative examples (optional)

direct local reader for raw read
Signed-off-by: fredchenbj <cfworking@163.com>
@sre-bot

This comment has been minimized.

Copy link
Collaborator

commented Feb 15, 2019

Hi contributor, thanks for your PR.

This patch needs to be approved by someone of admins. They should reply with "/ok-to-test" to accept this PR for running test automatically.

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 15, 2019

Thanks @fredchenbj

Can you give us the benchmark results compared to the previous implementation?

I guess the latency may be reduced.

fix little typos
Signed-off-by: fredchenbj <cfworking@163.com>
@fredchenbj

This comment has been minimized.

Copy link
Contributor Author

commented Feb 15, 2019

@siddontang OK, I will test the latency of raw_get and raw_batch_get using the go-ycsb to justify the effect of this change.

@fredchenbj

This comment has been minimized.

Copy link
Contributor Author

commented Feb 15, 2019

image

Left is using this change, right is old. From the image, grpc p999 duration decreases, and scheduler command duration decreases more effectively.

test command (only for raw_batch_get)

./bin/go-ycsb run tikv -P workloads/workloada -p tikv.pd="10.136.16.2:2379" -p tikv.type="raw" -p tikv.conncount=128 -p tikv.batchsize=128 -p batch.size=1000 --target=100000 --threads=32

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 15, 2019

Hi @fredchenbj

The scheduler command time looks zero, maybe there is something wrong for the metrics.

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 15, 2019

But through the gRPC metrics, we can see the latency reduces a lot, very cool.

@siddontang siddontang requested review from breeswish and overvenus Feb 15, 2019

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 15, 2019

seem you need to call _timer.observe_duration(); explicitly at the end of the future.

fix bug about _timer
Signed-off-by: fredchenbj <cfworking@163.com>
@fredchenbj

This comment has been minimized.

Copy link
Contributor Author

commented Feb 16, 2019

@siddontang OK, I have fixed this metric~

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 16, 2019

Thanks @fredchenbj

Please format your code and let CI passed.

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 16, 2019

how about the new fixed metrics?

what is the 999 read process duration?

})
.and_then(move |res| {
_timer.observe_duration();
let r = tx.send(res);

This comment has been minimized.

Copy link
@siddontang

siddontang Feb 16, 2019

Contributor

em, seem it must be sent successfully. do we need to panic here?

/cc @overvenus

This comment has been minimized.

Copy link
@zhangjinpeng1987

zhangjinpeng1987 Feb 16, 2019

Member

Agree, or the command will be blocked for ever.

This comment has been minimized.

Copy link
@ngaut

ngaut Feb 17, 2019

Member

Does it really helpful to add a timer metric here, The send method of tx should be fast or blocked, other metrics could be used to reflect the timer metric. And we can remove the metric in another PR.

This comment has been minimized.

Copy link
@overvenus

overvenus Feb 17, 2019

Contributor

seem it must be sent successfully. do we need to panic here?

By panicking, we may unable to shutdown tikv gracefully.


or the command will be blocked for ever.

It's a raw get, I think clients will timeout.


Does it really helpful to add a timer metric here, The send method of tx should be fast or blocked, other metrics could be used to reflect the timer metric. And we can remove the metric in another PR.

It does not record the send method, instead it records from L1108 to L1143, means how long it will spend for taking a snapshot and perform a raw get op.

little fix to pass make format
Signed-off-by: fredchenbj <cfworking@163.com>
r
})
});
let _timer = SCHED_HISTOGRAM_VEC

This comment has been minimized.

Copy link
@zhangjinpeng1987

zhangjinpeng1987 Feb 17, 2019

Member

@breeswish This metric is a global metric, does it matter? Is it possible to use its local method here?

This comment has been minimized.

Copy link
@siddontang

siddontang Feb 18, 2019

Contributor

I think we should use local metrics, but can do it in another PR.

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 19, 2019

Member

Looks like this is not necessary because there is thread_ctx.start_processing_read_duration_timer(CMD); inside. Sorry they are different timers. Looks fine.

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 19, 2019

Member

@siddontang Looks like it is not running on a thread pool or a read pool? Then it is not a local metrics any more. However static metrics is possible though.

This comment has been minimized.

Copy link
@siddontang

siddontang Feb 20, 2019

Contributor

yes, please file an issue to move to static metrics later
@breeswish

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 17, 2019

@hicqu @overvenus

seem reducing context switch can help us gain better performance, so I think it is worth to remove the scheduler and local read threads.

@overvenus
Copy link
Contributor

left a comment

LGTM, thank you!

@siddontang

This comment has been minimized.

Copy link
Contributor

commented Feb 19, 2019

PTAL @breeswish

@breeswish

This comment has been minimized.

Copy link
Member

commented Feb 19, 2019

How is the performance difference? (e.g. with go-ycsb)

Show resolved Hide resolved src/storage/mod.rs Outdated
Show resolved Hide resolved src/storage/mod.rs Outdated
@fredchenbj

This comment has been minimized.

Copy link
Contributor Author

commented Feb 19, 2019

@breeswish There is a simple go-ycsb test, #4222 (comment). From the test, the raw_batch_get grpc p999 duration reduces, and the context switch reduced about 15%.

@breeswish
Copy link
Member

left a comment

Thanks a lot! Mostly fine, but I'm concerned with the way dealing with errors. These errors should be returned through the function interface, making the function resolve to a failed Future (that's why the signature is impl Future<Item = ..., Error = Error> ).

_timer.observe_duration();
let r = tx.send(res);
if r.is_err() {
warn!("future callback: Failed to send result to the future rx, discarded.");

This comment has been minimized.

Copy link
@siddontang

siddontang Feb 20, 2019

Contributor

any case that the sending can fail?

@breeswish

r
})
});
let _timer = SCHED_HISTOGRAM_VEC

This comment has been minimized.

Copy link
@BusyJay

BusyJay Feb 21, 2019

Contributor

Name it as timer instead.

This comment has been minimized.

Copy link
@fredchenbj

fredchenbj Feb 21, 2019

Author Contributor

fixed it.

.flatten()
.map_err(|_| Error::SchedTooBusy)

This comment has been minimized.

Copy link
@BusyJay

BusyJay Feb 21, 2019

Contributor

This can be wrong as the result returned by async_snapshot can be various and needs to be handled properly to let client choose properly retry strategy.

This comment has been minimized.

Copy link
@fredchenbj

fredchenbj Feb 21, 2019

Author Contributor

Yes, this error handling will be changed properly.

fix typos of _timer
Signed-off-by: fredchenbj <cfworking@163.com>

fredchenbj added some commits Feb 21, 2019

handle errors more properly
Signed-off-by: fredchenbj <cfworking@163.com>
Show resolved Hide resolved src/storage/mod.rs Outdated
Show resolved Hide resolved src/storage/mod.rs Outdated
use another feasible way
Signed-off-by: fredchenbj <cfworking@163.com>
@breeswish
Copy link
Member

left a comment

Looks good but I'm afraid that it cannot compile? Wait for CI fix.

})
});
let readpool = self.read_pool.clone();
let region_id = ctx.get_region_id();

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 24, 2019

Member

maybe not necessary since we can just move ctx?

This comment has been minimized.

Copy link
@fredchenbj

fredchenbj Feb 24, 2019

Author Contributor

fixed it.

// let cf = Self::rawkv_cf(&cf)?;
let cf = match Self::rawkv_cf(&cf) {
Ok(x) => x,
Err(e) => return future::result(Err(e)),

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 24, 2019

Member

is this really able to compile 😅?

This comment has been minimized.

Copy link
@fredchenbj

fredchenbj Feb 24, 2019

Author Contributor

it can compile~

This comment has been minimized.

Copy link
@fredchenbj

fredchenbj Feb 24, 2019

Author Contributor

have passed ci ~

@@ -28,6 +28,7 @@ use std::io::Error as IoError;
use std::sync::{atomic, Arc, Mutex};
use std::u64;

use futures::sync::oneshot;

This comment has been minimized.

Copy link
@breeswish

fredchenbj added some commits Feb 24, 2019

fix little to pass ci
Signed-off-by: fredchenbj <cfworking@163.com>
remove unnessary variables
Signed-off-by: fredchenbj <cfworking@163.com>
future::result(result)
});
future::result(res)
.map_err(|_| Error::SchedTooBusy)

This comment has been minimized.

Copy link
@siddontang

siddontang Feb 25, 2019

Contributor

em, do we treat all errors as SchedTooBusy now?

@breeswish
Copy link
Member

left a comment

LGTM

let res = readpool.future_execute(priority, move |ctxd| {
let mut thread_ctx = ctxd.current_thread_context_mut();
let _t_process = thread_ctx.start_processing_read_duration_timer(CMD);
// let cf = Self::rawkv_cf(&cf)?;

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 25, 2019

Member

Remove this line

.map_err(|_| Error::SchedTooBusy)
.flatten()
let _t_process = thread_ctx.start_processing_read_duration_timer(CMD);
//let cf = Self::rawkv_cf(&cf)?;

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 25, 2019

Member

remove this line.

// let cf = Self::rawkv_cf(&cf)?;
let cf = match Self::rawkv_cf(&cf) {
Ok(x) => x,
Err(e) => return future::result(Err(e)),

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 25, 2019

Member

maybe just future::err(e)

thread_ctx.collect_read_flow(ctx.get_region_id(), &stats);

timer.observe_duration();
future::result(Ok(result))

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 25, 2019

Member

future::ok(result)

.map_err(|_| Error::SchedTooBusy)
.flatten()
timer.observe_duration();
future::result(Ok(result))

This comment has been minimized.

Copy link
@breeswish

breeswish Feb 25, 2019

Member

future::ok(result)

little fixes
Signed-off-by: fredchenbj <cfworking@163.com>
@breeswish

This comment has been minimized.

Copy link
Member

commented Feb 25, 2019

Good job!

@breeswish

This comment has been minimized.

Copy link
Member

commented Feb 25, 2019

/run-integration-tests

@overvenus
Copy link
Contributor

left a comment

LGTM

@overvenus overvenus merged commit 29d608a into tikv:master Feb 25, 2019

2 checks passed

DCO All commits are signed off!
Details
idc-jenkins-ci/test Jenkins job succeeded.
Details
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.