disk io引起golang线程数暴涨的问题

rfyiamcool · · 2405 次点击 · · 开始浏览    
这是一个创建于 的文章,其中的信息可能已经有所发展或是发生改变。

前言:

       我们知道golang对用户抽象了协程,协程要跑起来必然是需要系统线程来承载上下文,因为线程是最小的调度单元。golang的scheduler会帮你调度关联 PMG,这里的M是线程,G就是我们在golang里用go关键字spawn的协程。 对于用户来说,你是看不到也无法创建native thread原生线程的。 不管是golang nuts和golang issue里有人提过native thread feature的需求,但社区给出的论调是没必要,如果有必要那么可以用cgo,或者手动触发runtime.LockOSThread绑定。

       有些跑题,接着来。 golang抽象了pmg,  我们通常不会特意的去关注某个golang线程数目,但上次就遇到了golang线程异常暴增, 最多的时候涨到1300多个线程。那我们知道线程过多有什么问题? 每个pthread的stack栈空间是8MB, 当然是virt,  这些线程也会增加kernel的调度成本,光上下文切换就不是闹的。当然golang 不会这么傻,不会让这么多的线程去轮询P上下文队列, 应该会有条件变量去控制调度。


golang 线程暴增的原因?

     什么问题会导致产生这么多的线程? 我先告诉大家答案,在我的这个场景下是 因为磁盘io问题引起的。 因为一些杂七杂八的程序都在这台主机,iops过高,又因为是阿里云磁盘性能低下,又又因为内存被占用的差不多了…. 

     首先我们知道 golang写文件是阻塞,后面会说明原因。当我们写日志一般是先写到内核的page cache里,然后再由kernel通过阈值或定时刷新到磁盘,而不会像数据库那样调用fsync来磁盘落地。

     既然先写到page cache内存里应该很快呀。 但这台服务器上有不少相关的服务在跑,在压测的场景下会产生大量的日志,而大量的日志都会扔到page cahe里,但刚才说了不少相关的服务都在一台阿里云主机上,虽然这台阿里云是高配,但相关服务都是吃内存不吐骨头的角色,导致page cache的内存明显少了。既然内存少了,那么kernel调用sync来持久化,但又因为阿里云主机的磁盘io吞吐很可悲,导致不能很快的flush到磁盘上。 那么就导致golang写日志的线程越来越多。

     golang runtime是有个sysmon的协程,他会轮询的检测所有的P上下文队列,只要 G-M 的线程长时间在阻塞状态,那么就重新创建一个线程去从runtime P队列里获取任务。先前的阻塞的线程会被游离出去了,当他完成阻塞操作后会触发相关的callback回调,并加入回线程组里。简单说,如果你没有特意配置runtime.SetMaxThreads,那么在可没有复用的线程下会一直创建新线程。 golang默认的最大线程数10000个线程,这个是硬编码。 如果想要控制golang的pthread线程数可以使用 runtime.SetMaxThreads() 。



golang 磁盘io问题?

        golang针对网络io使用了epoll事件机制来实现了异步非阻塞,但磁盘io用不了这套,因为磁盘始终是就绪状态,epoll是根据就绪通知,就绪 & 非就绪状态。 现在常见的一些高性能框架都没有直接的解决磁盘io异步非阻塞问题。 像nginx之前读写磁盘会阻塞worker进程,只有开启aio及线程池thread才会绕开阻塞问题。 可以说,整个linux下,aio不是很完善,最少比bsd和windows平台下稍微差点。像windows下iocp就解决了磁盘io异步问题,但他的原理关键也是线程池。


如何分析问题?

      下面说下分析问题的过程,  首先通过ps和pprof看到golang的线程数,然后通过golang stack分析出当前的调用栈逻辑,继而通过strace来追踪系统调用情况。 golang stack没啥好说的,写日志阻塞那么调用栈里会显示不少log的调用情况。 那么我们主要来分析下,写日志和创建线程是怎么做的关联 ?  很简单就两个工具,一个是strace, 一个是 lsof 。

通过strace是可以看到write(8) fd的时候会mmap mprotect clone创建线程, 通过lsof 可以看到8是一个日志文件。配合Prometheus监控是可以看出iostat过高的时候,线程的数目也会跟着增长起来。 因为其他原因系统的内存也在减少,所以引起page cache不断刷盘。

golang 内置pprof的截图,我们可以看到1009个线程.


PS命令看到的线程数, 可以看到数目跟pprof是一致的。


当前的磁盘io使用情况, utils表示 长时间io吞吐 100%


通过Prometheus查看io wait的趋势,  下面的图表可以看出io等待时间还是蛮高的。


怎么解决?

上面说了,磁盘io造成golang线程暴涨是有很多原因的? 比如内存太小呀,日志输出太多呀,磁盘吞吐不行呀,各种各样的。 

我们的解决方法是 首先限制runtime的线程数为200个 ( runtime.SetMaxThreads ),一般正常情况下都够用了。 通常24 core cpu的环境下,一个高频的proxy服务正常压测也才80多个线程。 这里主要还是为了避免预防各种未知诡异问题。 

另外线上把服务的日志级别调高到warn警告,别整个debug level,导致io疯狂输出。

据我的测试,剩余的内存如果够大,也是可以减少线程的异常增长, 毕竟写日志O_APPEND按道理是速度很快的顺序io。 

fsync & sync

    还有一点,我先前使用过 golang的boltdb作为nosql存储,当机器磁盘的io吞吐不够的时候,也会产生线程过多的情况。当然数目没有1000,那时候也有400多个线程了。

    像boltdb当然不会实时的去修改b+tree数据文件, 而是采取绝大数db的wal日志模式。 wal虽然是顺序io,但他的wal日志是通过fsync的方式来落盘的。 通过我们写日志是通过sync方法写,也就是数据写到内存page cache就完事了,这里更改的脏页不会立即落盘,而是等kernel的flusher定时或者触发阈值来刷盘。

    刷盘的时候也只是把写请求放到设备的io请求队列里。 中间只有有一个环节crash掉,那么就拉稀了。这个fsync的功能就是确保文件修改的内容安全的同步到硬盘上,该调用会阻塞等待直到设备报告IO完成。  要注意,又是同步,又是阻塞等待,我想你懂了。

    boltdb后面的版本貌似解决了该问题,具体修改的逻辑没看,有兴趣的朋友可以看看。记得告诉我。

总结:

      到此为止,golang线程暴增的问题差不多说完了。写这篇文章废了不少时间,其实发现问题 到 解决问题,一共也才十来分钟。 当大家遇到一些性能问题时,使用golang pprof及性能工具来检查, 比较容易就可以定位问题。推荐大家使用Prometheus来监控系统,通过golang metrics模块可以把runtime信息及业务上的qps输出到Prometheus里。 当有问题的时候,配合前端利器grafna可以多维度来分析问题。 


有疑问加站长微信联系(非本文作者)

本文来自:峰云就她了

感谢作者:rfyiamcool

查看原文:disk io引起golang线程数暴涨的问题

入群交流(和以上内容无关):加入Go大咖交流群,或添加微信:liuxiaoyan-s 备注:入群;或加QQ群:692541889

2405 次点击  
加入收藏 微博
暂无回复
添加一条新回复 (您需要 登录 后才能回复 没有账号 ?)
  • 请尽量让自己的回复能够对别人有帮助
  • 支持 Markdown 格式, **粗体**、~~删除线~~、`单行代码`
  • 支持 @ 本站用户;支持表情(输入 : 提示),见 Emoji cheat sheet
  • 图片支持拖拽、截图粘贴等方式上传