client性能问题,txn写入速度比sysbench的要慢10倍,而且会出现TSO 的warn(补充: 增加线程似乎可以打破性能瓶颈,但是内存持续增长)

  • 【TiDB 版本】: v4.0.0
  • 【问题描述】:通过go client的写入速度比sysbench的要慢,而且会出现WARN[0058] get timestamp too slow: 235.40136ms 之类的打印

测试代码:
type worker struct{
id int
}

func newWorker(i int) *worker{
instance := new(worker)
instance.id = i
return instance
}

func (w *worker) start(k string, v string) {
go func() {
_k := k + strconv.Itoa(w.id)
_v := v + strconv.Itoa(w.id)
_key := []byte(_k)
_val := []byte(_v)
for {
txnentry(_key, _val)
}
}()
}

var pdAddr = flag.String(“pd”, “127.0.0.1:2379”, “pd address”)

var txnclient *txnkv.Client

func initDB() {
// todo: txnclient
var (
err error
)
addr := os.Getenv(“PD_ADDR”)
if addr != “” {
os.Args = append(os.Args, “-pd”, addr)
}
flag.Parse()

txnclient, err = txnkv.NewClient(context.TODO(), []string{*pdAddr}, config.Default())
if err != nil {
	panic(err)
}

}

func getKey(keyLen int) (keystr string){
pwd, _ := os.Getwd()
_len := strconv.Itoa(keyLen)
targetFile := pwd + “\test” + _len + “file”
key, err := ioutil.ReadFile(targetFile)
if err != nil{
}
keystr = string(key)
return keystr
}

func getValue(valueLen int) (valuestr string){
pwd, _ := os.Getwd()
_len := strconv.Itoa(valueLen)
targetFile := pwd + “\test” + _len + “keyfile”
value, err := ioutil.ReadFile(targetFile)
if err != nil{
}
valuestr = string(value)
return valuestr
}

func txnentry(_key []byte, _val []byte){

// todo: txn put
txn, err := txnclient.Begin(context.TODO())
if err != nil{
	panic(err)
}
{
	err := txn.Set(_key, _val)
	if err != nil {
		panic(err)
	}
}
txn.Commit(context.Background())

// todo: get
txn, err = txnclient.Begin(context.TODO())
if err != nil{
	panic(err)
}
{
	_, err := txn.Get(context.TODO(), _key)
	if err != nil {
		panic(err)
	}
}

// todo: del
txn, err = txnclient.Begin(context.TODO())
if err != nil{
	panic(err)
}
{
	err := txn.Delete(_key)
	if err != nil {
		panic(err)
	}
}
txn.Commit(context.Background())

}

func main(){
go func() {
http.ListenAndServe(“0.0.0.0:9999”, nil)
}()

key := getKey(1)
val := getValue(1)

initDB()

for i := 0;i<10;i++{
	worker := newWorker(i)
	worker.start(key, val)
}
for{

}

}

测试时发现cpu占用一直飙高,sysbench的性能可以达到97k ops,通过go client的方式测试性能只有9K ops,差距在10倍左右。示例代码中key的大小为128字节,value的大小为1KB,测试发现cpu的占用率很高,通过pprof包测试,占用较高的函数如下图

补充一幅对比图,希望有人帮忙看下问题

更新一下问题。看来是我太温柔了,之前只用了10个线程,把线程加到50个,性能到了35KOPS.但是top一下,发现内存持续增长,最终挂掉了
报错信息如下

可以试下按照这个试下新 cient https://tikv.org/docs/4.0/reference/clients/go/

看起来我用的就是这个,是不是txn.set之后还需要释放内存之类的呢?内存一直在涨

请问用的是 kv-only-4.0 分支吗?

重新生成了一下mod文件,编译出现了错误


麻烦指导一下这是什么情况


出现了很多奇怪的编译依赖问题

更新一下问题,我改了go.mod中的pd版本把github.com/tikv/pd v2.1.19+incompatible // indirect换成了
github.com/tikv/pd v0.0.0-20210105112549-e5be7fd38659 // indirect
但是有出现了tidb的问题

你试下把那个分支clone到本地,然后让测试replace 本地的tidb

编译问题解决了,测试了一下,发现没有内存飙高的问题了,内存很稳定。
只不过这次的客户端会不断的打印一下info日志

看了一下代码,看见这里是在prewrite中触发了error,但是看起来这个error并不是重要,所以只是打印了日志就继续进行循环,可以解释一下为什么会触发这个error吗?

此外获取tso的warn还是会有,不过打印不是很频繁了,


这个延时是否会对性能产生影响。
我现在怀疑是由于我PD+TIKV部署在一块盘上引起的

这说明乐观事务发生了冲突重试就行,要避免冲突可以用悲观事务

此外获取tso的warn还是会有,不过打印不是很频繁了,这个延时是否会对性能产生影响。

确实会影响性能,得找找具体原因 @yilong

谢谢, 这个问题很奇怪,通过sysbench的测试方式,pd日志里面没有打印过这个tso的warn,但是通过client的方式就会打印
@yilong 可以帮忙分析一下嘛

请问测试的代码和sysbench 的代码是一样的吗? 这两个对比是否合理呀?

您好,不是一样的,sysybench直接用的提供的lua脚本,测试代码是依赖于go-client,代码主贴中已经贴出来了,有一些修改,但是差别不大,就是不停的循环put delete

好的,那麻烦您导出下 pd 和 tikv 测试时的监控吧,多谢。

tidb-test-TiKV-Details_2021-01-21T02_27_36.912Z.json (5.5 MB)

上午简单跑了15分钟,100个线程并发执行事务,发现与50个线程并发比较,性能没有什么变化。
当tso的warn告警延时到达200ms时,性能出现抖动,已经把grafana的性能数据导出。麻烦帮忙分析一下,谢谢

多谢,tikv 看起来有一些 store 的 IO 使用率 100%, 麻烦您反馈下 pd 的监控吧,之前看主要问题是 pd tso 可能慢

tidb-test-PD_2021-01-21T08_35_18.408Z.json (3.1 MB)
已上传,不知道传的对不对

  1. pd监控看起来tso时间比较低
  2. 按照写入流程查看 append log apply log 等都比较快
  3. 查看 cpu 和 IO 看起来比较高,感觉可以从系统上检查下是否达到瓶颈 cpu,内存,io,另外看下网络是否打满。