一个内部API系统的性能优化

紫火神兵 2018-12-18

展开全文

这个API系统的本身目的是解决大量并发关系数据库查询的问题，主体设计思路是对PG中的表数据通过LRU等缓存算法缓存其中的数据，并进行请求合并也就是请求削峰服务，从而大量减少直连数据库操作，减轻数据库的压力，查询效率也大大提高。由于这个项目第一版各种指标要求不是很高，接着就面临一系列严重的问题：包括无法承载百万终端级别的数据；请求压力过大请求失败；内存和CPU在请求高峰时打满；出现goruntine崩溃和map读写冲突问题；性能和预期差的很远。独自接下优化这个项目后不得不一点dian回归重构，期间也就遇到了很多坑。。。

此次优化更多的是算法和Go使用技巧和特性的优化，包括简化递归算法的设计加速启动数据加载，数据结构的精简，缓存以及数据的复用共享减少内存压力，内存和CPU暴增的排查，定位和解决，GC与内存分配的优化，channel的使用坑，计时器的使用误区等等。对其中重要的我将通过几个真实的场景问题来介绍。

1.启动时数据库缓存数据加载优化

场景：API系统开启后需要快速的将100W终端的详细信息以及它们组成的大约1-10W不等分组信息从数据库中加载出来，但是速度特别慢100W数据需要大概1分钟以上，10W分组需要二十多分钟才能完全load下来。

100W的数据想要一条SQL查询下来并缓存肯定会出现不可预期的问题，数据量太大，这样搞最后肯定会卡死。所以采用切分策略，每次只取2000条左右，大概要取50次，ok，这没问题。问题出在如何切分以及下次从哪里开始查询，原先代码如下：

var minId int
  ShovelSize ＝ 2000
  if err := Pg.Get(&minId, "SELECT MIN(id) FROM client"); err != nil {
    return err
  }
  // 得到最小的id
  lastSyncedID := minId
  for {
    var thisQueryResultCount = 0
    // 然后查询id>lastSyncedID的数据
    rows, err := Pg.Queryx(fmt.Sprintf(`SELECT id,mid,gid 
      FROM client WHERE id >= %d ORDER BY id ASC LIMIT %d;
        `, lastSyncedID, ShovelSize))
    /.../
    // 每次lastSyncedID+2000
    lastSyncedID += ShovelSize
    for rows.Next() {
      thisQueryResultCount++
      ...
      err = rows.StructScan(&c)
      api.clientMgr.ReplaceInto(&c)
      // lastSyncedID = c.Id +1
    }
    if thisQueryResultCount == 0 {
      break
    }
  }

从上面的代码可以看出问题所在，当这100W数据id是连续的，每次取2000条然后每次lastSyncedID加2000没问题，一旦出现断了的id，就会出现重复的查询，而插入缓存的代码还要判断是否目前存在了该信息，存在了还要覆盖或者删除再添加，只要出现一个id中断要重复50次左右，出现100个中断将重复50000次的删除写入操作。所以需要修改两个地方，一个是lastSyncedID = c.Id +1,即随着每次查询更新最后面的id，不再盲目的直接增加2000，这样我们保证了每次查出来的信息都是与之前没有重复的，另一个是将Replace直接用Add替换，因为可以放心的直接插入不用再像之前那样判断很多项是否存在，然后再插入。这样100W的终端数据缓存速度在几秒钟就完成啦。

2.精简递归算法提高查询效率

场景：影响初始化速度的另一个因素是每次加入一条分组信息要回归所有的子分组和父分组的children信息，更新数据，10W条分组要递归10W次，导致10W数据要20+分钟才能加载完。通过gid获取该分组的所有子孙分组以及从顶层到该层的分组路径，当查询gid＝1时需要60s+，如何优化？并且一旦有一个分组的信息改变可能需要递归所有相关的分组缓存信息，如何做到？

递归算法是一种直接或者间接调用自身函数或者方法的算法。实质是把问题分解成规模缩小的同类问题的子问题，然后递归调用方法来表示问题的解。递归是一门伟大的艺术，使得程序的正确性更容易确认，而不需要牺牲性能，但这需要我们能将复杂的问题抽象出最简单的数据模型来实现，使用不当不仅效率大大下降，有时候还会出现意外的崩溃。之前刷ACM题的时候就和同学经常说大部分的算法题都可以用二叉树和递归解决，真实场景确实也如此。

10W分组的数据，每个分组带有分组的id以及父分组的id，还有分组信息的更新时间等一些信息，程序原先的方法是缓存下来所有的分组信息，并一一计算它所有的children的id，一旦有一个分组出现修改要回滚计算所有的children分组和父分组，计算量还是非常大的，试想分组id如果是1，将重新递归计算10W分组信息。但我分析了下数据特征发现这些复杂数据的递归本质上是不必要的。

原始代码片段：

groupTbl    map[int]*RawGroupinfo
  type GroupCalcResult struct {
      Children   []int
      Path       []int
      OutputJson []byte
  }

       func getAllchildrenbyid(id int, children []int, recursiveChildrenNum int, maxRecursive int) ([]int, int) {
    isEnd := 0
    recursiveChildrenNum++
    if recursiveChildrenNum <= (maxRecursive + 1) {
        allFirstInfo := gm.groupTbl
        for childrenkey, childrenvalue := range allFirstInfo {
            if childrenvalue.Pid == id {
                children = append(children, childrenkey)
                children, isEnd = getAllchildrenbyid(childrenkey, children, recursiveChildrenNum, maxRecursive)
            }
        }
    } else {
        isEnd = 1
    }
    return children, isEnd
}

可以看到这个递归使用上没有什么问题，在数据量不大的情况下问题同样可以解决，但是我们可以看出一点，就是关注的信息太多，返回值太多，而这些值对于我们问题本身并没有什么必要用处，我们关注的就是id之间的父子关系，并且递归过程还出现了map读写冲突的bug，而这些读写是不必要的，也不是我们问题的关键。最初我以为是递归算法本身的问题，我照着上面的结构撸了个多叉树期望在算法效率上解决这个问题，经过测试我发现关注的信息太多并没有明显的优势。经过仔细分析，其实我们关注的无非就是int型的id以及id之间的上下级关系嘛。我们抽象下这个数据结构，10W分组的数据，结构如下：

1:[2,3,4,5,6,7,8,9]
2:[11,12,13,14,15,16,...]
11:[110,111,112...]
....

首先，我们不能时时刻刻维护这一个数组来保存着子子孙孙，只需要关注自己的儿子，不然怎么管的过来，还有就是对于没用的每个分组的附加信息在我们的关系结构中根本不需要，试想我们知道一个人和自己的关系，还需要带上他穿多少衣服，今天吃了什么吗？两个数据结构就可以维护我们的分组信息，10W的分组详细信息：map[gid]GidInfo和分组的父子信息map[id][]int。优化后

// 某个组id的children查询
func childrenSearch(groupFamily map[int][]int, data []int) []int {
  res := make([]int, 0)
  for _, v := range data {
    res = append(res, v)
    res = append(res, childrenSearch(groupFamily, groupFamily[v])...)
  }
  return res
}

经过测试后， 10W分组的id查询时间从之前的60s+变成了0.1s左右。

3.golang程序的内存占用不是你看到的内存实际占用

场景：通过gid获取全部的终端信息，请求查询gid＝1时返回数据大概32Mb，上百并发时16G内存的服务器一下子占用了其中的12G+，如何降低？

一个请求的返回数据32M，当同时有上百个这样的请求发起时内存暴增12G，当时的我是崩溃的，一遍遍的过代码，看pprof的内存数据，始终没有发现内存泄漏的问题，后来才发现，这个问题其实不是我看到的问题表面原因或者说问题是为何内存长时间占用不释放，并发请求过来内存暴增其实是正常的，因为毕竟一个请求就32M，好几百个请求同时过来不暴增才怪。

这里其实是Golang内存分配认识的一个坑：为了保证程序内内存的连续，Golang会申请一大块内存（甚至只写一个hello, world可能都会占用100M+内存）。当用户的程序申请的内存大于之前预申请的内存时，runtime会进行一次GC，并且将GC的阈值翻倍。也就是说，之前是超过4M时进行GC，那么下一次GC就是超过8M才进行。我们内存暴增的原因，就是访问量过大导致内存申请，并且GC阈值也一下子变大，回收频率变低，同时GC还预测以后可能还会需要这块大内存为了优化内存分配就一直不释放给系统啦。而且Golang采用了一种拖延症策略，即使是被释放的内存，runtime也不会立刻把内存还给系统，而是在自己不需要并且系统需要的情况下才回还给系统。这就导致了内存降不下来，一种内存泄漏的假象。所以难怪我一直找不到内存泄漏原因。

找到原因之后，解决方案是定时将不需要的内存还给操作系统，debug.FreeOSMemory(),不过这个请慎用，最好不用，最好的解决方案是：

1.尽量减少对象创建

2.尽量做到变量复用，很多采用共用buffer来减少内存分配

3.如果局部变量过多，可以把这些变量放到一个大结构体里面，这样扫描的时候可以只扫描一个变量，回收掉它包含的很多内存

4.CPU随着时间持续增长

场景：在系统刚调试完成，请求正确处理的那一刻内心是激动的，然后当服务开启之后，习惯性的查看了下功耗，内存使用正常，CPU却在眼下不断增高，2%－5%－10%－20%－50%－80%－100%，在短短几分钟就飙到了100%。。。内心是崩溃的，此时刚从一堆代码中缕顺流程。如何快速的定位到问题？我应该从哪些方面下手，或者说我应该查看哪些数据来推测所有的可能性？究竟是哪个package，哪个函数甚至是哪一行代码影响了它的性能？这里主要说明排查定位过程。

1.遇到这种情况最先想到的是死循环的情况，回到代码，检查有没有死循环之类的bug,仔细看了下所有可能存在循环的地方，并没有发现，而且从症状来看不像是死循环的情况(如果是死循环的情况，CPU的增长不会那么慢，肯定是要立即上去的)

2.打开GC看看是不是由于GC次数过多占用CPU，GC明显是2分钟一次属于默认的情况，所以也不是GC频繁导致的

3.此时只有pprof了，查看程序的运行时数据

开启pprof接口查看运行时cpu数据和heap数据。

从上面的截图可以看出flat%最高的是rumtime.mach_semaphore_signal方法,在这里只有28%左右其实更高，达到60+%（此图截错了，罢了，罢了，在此说明问题就行）。Ok，知道了到底是什么导致的CPU高，下面我们追溯下代码路径，在此我使用火焰图来分析，更加直观。

从火焰图我们可以很方便的分析各个方法占用的CPU的时间。它是SVG格式的，鼠标放上去还能看细节。Y轴是栈的深度，X轴是所有的采样点的集合，每个方框代表一个栈帧(stack frame)。颜色没有意义，只是随机的选取的。左右顺序也不重要。看的时候可以从最宽的帧看起，从底往上看，帧上的分叉代表不同的代码路径。快速识别和量化的CPU使用率

从火焰图的信息可以看到，在整个cpu占用信息采集过程中几乎全部都是runtime的信息，并且是runtime.timerproc。通过分析go语言的源码我们可以知道这是一个定时器调度goruntine。（代码是go1.7.3源码，我经过了裁剪，保留大意）

调度流程分析如下：

1.判断堆中是否有Timer? 如果没有就将Timers的rescheduling设置为true的状态，true就代表timerproc goroutine被挂起，需要重新调度。这个重新调度的时刻就是在添加一个Timer进来的时候，会ready这个goroutine。这里挂起goroutine使用的是runtime·park()函数。

2.如果堆中有Timer存在，就取出堆顶的一个Timer，判断是否超时。超时后，就删除Timer，执行Timer中挂载的方法。这一步是循环检查堆，直到堆中没有Timer或者没有超时的Timer为止。

3.在堆中的Timer还没超时之前，这个goroutine将处于sleep状态，也就是设置Timers的sleeping为true状态。这个地方是通过runtime·notesleep()函数来完成的，其实现是依赖futex锁。这里，goroutine将sleep多久呢？它将sleep到最近一个Timer超时的时候，就开始执行。

从火焰图往上或者我们从pprof的cpu走向来分析（如下图）看就可以看到我们上面提到的runtime.mach_semaphore_timewait。所以在此我们可以推断，根源就在定时器的使用，那么全代码搜索所有使用time包方法的代码。发现是和time.Tick()和time.After()两个函数相关。那么问题就出在这里啦。

上面这两个例子，单独执行，不会发现任何问题，但是当你将这样的代码放到一个7 * 24小时的Service中，并且timeout间隔为更短时间，比如0.1s时，问题就出现了。

最初我怀疑是不是代码中有死循环，但仔细巡查一遍代码后，没有发现死循环的痕迹，算法逻辑也没问题。于是重启了一下这个service，发现cpu占用降了下来。继续用top观察，不好，这个service占用了1%的CPU一直上升，观察一段时间后，发现这个service对cpu的占用率随着时间的推移而增加。

从火焰图上可以看出几乎都是timeproc goroutine的调度。回到代码，发现可能存在问题的只有这里的tick和after。

回到我们的代码，timerproc指针维护的是一个goroutine，这个goroutine的主要功能就是检查小顶堆中的Timer是否超时。当然，超时就是删除Timer，并且执行Timer对应的动作。我的Timer间隔是1s。这样每1s都会创建一个runtime timer，而通过runtime的源码来看，这些timer都扔给了runtime调度(一个heap)。时间长了，就会有超多的timer需要 runtime调度，不耗CPU才怪。

找到原因之后，继续分析了造成timer过多的原因，一个是配置项中的时间间隔太小(0.1s)一个是上面看到的代码逻辑bug，两者一起造成了CPU飙升.修复代码中存在的bug，调节参数间隔大小.CPU立马降了下来。

那么问题来了我们应该如何正确使用定时器呢？

正常情况下，Tick代表是永久的闹钟，只要你定时了以后就定时叫醒你，After更像是一次性闹钟，到了时间叫醒你，如果你没有接收到，那么它也会停止失效。所以Tick可不要放在循环里面，不然会一直增长下去。但是像左侧第二个你回发现它的位置并不是最里面的循环，所以并没有原则上的不允许，要在具体情况下选择正确的方法。

5.channel长度的陷阱

场景：这是客户那里发现的一个很深的bug，说它深是，这个bug会在正常启动程序后，接收到请求后中断数据库才可以触发。

之前写C/C++时经常坚守的一个规则是在使用数组时，如果要遍历要首先获取到数组的长度，然后再去遍历它，而不是直接在for循环中求长度，因为一旦数组有变化会导致不可预期的bug，但通常直接写在循环中是可以的，所以很多人会习惯这个写法。一般的程序还好，但是在golang中最好不要这样，因为在并发中这样写非常容易出错，例如：

if subChain, ok := psgrRegister[strings.Join(psgr, `-`)]; ok {
  // 此处应该注意不能直接在循环里面使用len()，因为一旦close一个chan这个数字就变了，会导致严重bug
  BROADCASTLOOP:
    for i := 0; i < len(subChain); i++ {
      select {
      case waiter := <-subChain:
        waiter <- msg
        close(waiter) // 一旦close chan的长度会减少1
      default:
        break BROADCASTLOOP
      }
    }
    close(subChain)
}

可以看到每当close一个chan原先的chan数组元素个数就减少了1，所以在并发请求过来后发现最后的几个请求结果是null，就是因为在这里提前结束了。

6.数据库触发器和goruntine的配合使用

场景：在给某银行60W终端压力测试过程中，出现内存占用暴增的情况，原因是API缓存系统一个重要功能就是监控数据库状态并及时同步数据变更，我们采用的触发器的形式通知API系统，压力测试时，频繁的改动和表变更导致开启了大量goruntine处理数据，高峰时堆积达到几百万个

这个原因是两个方面，一个是我们的数据处理很慢，大概可以达到每秒几十个的样子，后来经过我优化提升了十倍左右能每秒处理上百个但没有解决根本问题，另一个重要问题是设计上的问题，也就是我们两个业务共用了一个触发器，但其中一个只对表中的四五个字段感兴趣，其他修改不修改无所谓，但我们没有分开，导致大量变更触发，而我们这部分逻辑的处理性能达不到，导致了这个问题。这个问题在刚接手这个项目时考虑到了这个潜在问题，但当时一直没有问题，索性没有理会它，成功的验证了墨菲定律。