前往小程序,Get更优阅读体验!
立即前往
首页
学习
活动
专区
工具
TVP
发布
社区首页 >专栏 >Golang又一个和RLock有关的小故事

Golang又一个和RLock有关的小故事

原创
作者头像
乔碧萝殿下
修改2019-12-26 17:25:49
1.9K0
修改2019-12-26 17:25:49
举报
文章被收录于专栏:inging

一. 背景

前几天看了一篇golang的文章一个和RLock有关的小故事, 发现作者得到的结论是错误的, 实际涉及内容比作者讲解的多一些。

二. 错误结论

先看下面的代码, 此段代码表现为sync.RWMutex的RLock操作效率极低。

代码语言:txt
复制
package main
import (
	"fmt"
	"os"
	"runtime/trace"
	"sync"
	"time"
)
var mlock sync.RWMutex
var wg sync.WaitGroup
func main() {
	trace.Start(os.Stderr)
	defer trace.Stop()
	wg.Add(100)
	for i := 0; i < 100; i++ {
		go gets()
	}
	wg.Wait()
}
func gets() {
	for i := 0; i < 100000; i++ {
		get(i)
	}
	wg.Done()
}
func get(i int) {
	beginTime := time.Now()
	mlock.RLock()
	tmp1 := time.Since(beginTime).Nanoseconds() / 1000000
	if tmp1 > 100 { // 超过100ms就打印出来
		fmt.Println("fuck here")
	}
	mlock.RUnlock()
}

某一次的控制台输出样式:

1574766952_60_w483_h322.png
1574766952_60_w483_h322.png

整个代码片只涉及RWMutex的RLock和RUnlock, RLock是不相互影响的, 我们可以理解为只涉及atomic.AddInt32。

但是代码执行过程偶尔打印"fuck here", 表明某些时候RLock耗时超过100ms, 这对我们来说应该是impossible。

1574766964_45_w1218_h514.jpg
1574766964_45_w1218_h514.jpg

作者查看某个grontinue表明是syscall blocking, 其实是正常的调度。

1574766971_55_w1208_h560.jpg
1574766971_55_w1208_h560.jpg

作者用go tool对trace分析得到Goroutine执行结果统计, 看到goroutine存在blocking syscall就武断的认为是syscall原因引起

作者解释原因是:goroutine在RLock后, 因为要调用time.Since(time.Now)的syscall被runtime调出, 后随缘被系统再次调度, 这个随缘可能耗时超过100ms. 但是这个结论50%是错误的, 50%是正确的

三. time.Now()的实现

golang的time.Now最终调用是用汇编实现的代码, 代码精简后如下。

我们从代码中可以发现得到时间用的的vdso方式的调用, 因为有些内核使用太频繁, 每次都内核调用开销太高, 就将用户态的一段内存映射到内核, 这样内核调用就转换成用户态函数调用和内存读取。

代码语言:txt
复制
// func walltime() (sec int64,  nsec int32)
TEXT runtime·walltime(SB), NOSPLIT, $0-12
	...
	MOVQ	g(CX),  AX
	MOVQ	g_m(AX),  BX // BX unchanged by C code.
	MOVQ	0(SP),  DX
	MOVQ	DX,  m_vdsoPC(BX)
	LEAQ	sec+0(SP),  DX
	MOVQ	DX,  m_vdsoSP(BX)
	CMPQ	AX,  m_curg(BX)	// Only switch if on curg.
	...
noswitch:
	...
	MOVQ	runtime·vdsoClockgettimeSym(SB),  AX
	...
    MOVQ	$0,  m_vdsoSP(BX)
	...
fallback:
	...
	MOVQ	runtime·vdsoGettimeofdaySym(SB),  AX
	...
    MOVQ	$0,  m_vdsoSP(BX)
	...

walltime涉及的vdso库的解析.

代码语言:txt
复制
var vdsoSymbolKeys = []vdsoSymbolKey{
	{"__vdso_gettimeofday",  0x315ca59,  0xb01bca00,  &vdsoGettimeofdaySym}, 
	{"__vdso_clock_gettime",  0xd35ec75,  0x6e43a318,  &vdsoClockgettimeSym}, 
}

当然上面代码阅读起来还是有点困难, 进行翻译以后就是下面的代码, vdso_clock_gettime的精度是纳秒而 vdso_gettimeofday的精度是微秒。

代码语言:txt
复制
type timespec struct {
    sec  int64
    nsec int64
}

type timeval struct {
    sec  int64
    usec int64
}

func walltime() (sec int64,  nsec int32) {
    if __vdso_clock_gettime != nil {
        t := &timespec{}
        __vdso_clock_gettime(CLOCK_REALTIME,  t)
        return t.sec,  int32(t.nsec)
    }
    t := &timeval{}
    __vdso_gettimeofday(t,  nil)
    return t.sec,  int32(t.usec * 1000)
}

在walltime确实涉及到GPM中G和M的调度m_curg, 但是这个只是使用线程M的调度器G0的栈而已, 只因为G0的栈比普通的栈大, 而vdso调用需要的栈比较大而已。

四. syscall blocking

通过上面的分析可以看出整个time.Now()操作都是同步完成, 不涉及syscall blocking。

那文章作者的syscall blocking怎么来的呢?我们可以在本地跑一下代码, 我们选择个配置比较差的环境跑程序, trace后查看具体的阻塞goroutine的event。

1574767010_18_w1194_h424.png
1574767010_18_w1194_h424.png

生成syscall blocking图如下

1574767018_63_w396_h455.png
1574767018_63_w396_h455.png

可以看到这个syscall blocking是因为这段代码调用标准输出打印信息导致, 追踪fmt.Println("fuck here")最终定位到下面的代码, 在代码里边存在.

代码语言:txt
复制
func WriteFile(handle Handle,  buf []byte,  done *uint32,  overlapped *Overlapped) (err error) {
	var _p0 *byte
	if len(buf) > 0 {
		_p0 = &buf[0]
	}
	r1,  _,  e1 := Syscall6(procWriteFile.Addr(),  5,  uintptr(handle),  uintptr(unsafe.Pointer(_p0)),  uintptr(len(buf)),  uintptr(unsafe.Pointer(done)),  uintptr(unsafe.Pointer(overlapped)),  0)
	if r1 == 0 {
		if e1 != 0 {
			err = errnoErr(e1)
		} else {
			err = EINVAL
		}
	}
	return
}

函数调用的都是syscall一簇函数系列, 此系列函数还有Syscall/RawSyscall/RawSyscall6等, 这些函数在runtime中都是汇编实现, 我们抽取其中一个来进行分析, 这里边最关键的就是runtime·entersyscall和runtime·exitsyscall两个函数。

代码语言:txt
复制
TEXT ·Syscall(SB), NOSPLIT, $0-56
	CALL	runtime·entersyscall(SB)
	...
	SYSCALL
	...
	CALL	runtime·exitsyscall(SB)
	RET
ok:
	...
	CALL	runtime·exitsyscall(SB)
	RET
  • runtime·exitsyscall粗略执行逻辑:通知系统调用时候,是会将grontinue的M的P解绑,P可以去继续获取M执行其余的是会将grontinue的M的P解绑,这样提升效率。
  • runtime·exitsyscall粗略执行逻辑: 通知调度系统, 解除grontinue与M的绑定, 将M加入到空闲队列, 将grontinue放入到全局调度队列中。

从上面的分析可以得出结论是WriteFile调用Syscall6导致syscall blocking。

五. 正确结论

在grontinue执行到下面函数中间时候被调去, 然后随缘调度, 等调度回来的时候超过100ms。

代码语言:txt
复制
 mlock.RLock()
 //here
 tmp1 := time.Since(beginTime).Nanoseconds() / 1000000

六. 真正syscall blocking实验

我们来个mlock.RLock()后真实存在需要syscall blocking的操作来测试一下。

因为比较喜欢window系统所以选择window下的os.Getenv来测试。

注意在linux下os.Getenv实现和window不同。

代码语言:txt
复制
func GetEnvironmentVariable(name *uint16,  buffer *uint16,  size uint32) (n uint32,  err error) {
	r0,  _,  e1 := Syscall(procGetEnvironmentVariableW.Addr(),  3,  uintptr(unsafe.Pointer(name)),  uintptr(unsafe.Pointer(buffer)),  uintptr(size))
	n = uint32(r0)
	if n == 0 {
		if e1 != 0 {
			err = errnoErr(e1)
		} else {
			err = EINVAL
		}
	}
	return
}

测试的部分代码逻辑如下, 我们只选择创建3个goroutine, 100个goroutine信息太多图会生成失败。

代码语言:txt
复制
var buf bytes.Buffer
func get(i int) {
	mlock.RLock()
	env:=os.Getenv("aaa")
	if env!=""{
		env=""
	}
	buf.WriteString(env)
	mlock.RUnlock()
}

生成的goroutine调度远比没有syscall blocking的复杂。

1574767051_63_w1660_h551.png
1574767051_63_w1660_h551.png

生成syscall blocking图如下:

1574767058_85_w410_h360.png
1574767058_85_w410_h360.png

原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。

如有侵权,请联系 cloudcommunity@tencent.com 删除。

原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。

如有侵权,请联系 cloudcommunity@tencent.com 删除。

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
目录
  • 一. 背景
  • 二. 错误结论
  • 三. time.Now()的实现
  • 四. syscall blocking
  • 五. 正确结论
  • 六. 真正syscall blocking实验
领券
问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档