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

前言:

我们知道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可以多维度来分析问题。