记一次Sentry的性能调优过程

大概从6月底开始，我们的Sentry（错误日志收集、聚合和报警系统 http://getsentry.com ）遭遇了性能问题，每分钟只能处理200个事件了，经常有20多万待处理的任务积压在events队列里，延迟超过一小时，我不得不丢弃这些任务，清空队列，以促进时效。重启一下celery worker会有瞬间的改善，但很快就又不行了，似乎worker的性能会衰减。为此，我给celery worker增加了–time-limit参数，使worker不会在执行不下去的时候无限等待，而是超时出错退出，迎接新的任务，情况略有改善。

因为Sentry的结构是前端web-消息队列-后端celery这样的结构，给调试也造成了一些困难。

我先开启了celery worker的DEBUG级别日志，从中搜索包含succeed的行，然后把其中UUID给过滤掉，只保留任务名字和耗时，整理后得到任务和耗时的对应关系，发现save_event这个任务的耗时很有意思，经常是6秒的整倍数。

然后去这个任务里添加时间打点代码，发现在它调用的EventManager.save()函数里，带事务执行的三次数据库插入（调用_save_aggregate、创建EventMapping、保存Event）的耗时，不是零点几秒，就是六秒的整倍数，而完全没有2、3秒、7、8秒这种情况。于是检查的方向就被引导到了数据库方面。折腾了DBA同事几天，删了几个索引和外键约束，也没什么改善。

想到之前为了Sentry的下一个版本v8准备过一套PostgreSQL数据库用于测试，我就拿过来，另外建了一套Sentry 7的部署，在上面运行，没想到性能极其丝滑……事情似乎越来越明了，就是数据库的问题。不过当我停止使用用于测试的128G内存真机PostgreSQL，而自己申请了一个和当前MySQL一样配置的16G机器的时候，发现低配置时pgsql的性能好像还不如MySQL……不过就在我从真实环境往测试环境export/import数据的时候，发现了Sentry在执行import时，如果测试环境共用生产系统的Redis，就会速度极慢，几乎卡死，用strace上去看一下发现慢在Redis操作上，开销在数据库上的时间极少；而如果用专用的一套Redis就速度极快。

于是我的注意力又转向了Redis。尝试FLUSHDB，发现性能立刻恢复了每分钟4000条、峰值8000条的处理能力，但redis的内存碎片率上涨了不少。看了看SLOWLOG，发现有一条几乎占满了整个SLOWLOG排行榜的命令

ZRANGE b:p 0 -1

手工试了试，这条命令得好几秒种才能返回，一次就能返回数据好几万条。搜了一下源代码，在sentry/buffer/redis.py文件发现了b:p这个key名字。原来，这是把高速更新的计数器的多次更新合并起来，减轻数据库压力的一个组件。但这个组件本身因为把sorted set用到了极限，所以性能不佳。考虑到不能再让碎片率上涨，我只好偶尔手工删除这个key，放弃一些计数器更新操作：放弃更新计数器总比放弃整个任务看起来要好些吧。

去软件原厂求助（https://github.com/getsentry/sentry/issues/3870），作者说我该上供啦，不要自己架服务啦，还是买原厂服务吧……

现在，我更改了worker的配置，把这个任务单独拉出来，用六台worker伺候着，终于基本解决了问题。

顺便说一下我在Redis 2.8.7上遇到的极限值：

sorted set的长度在100万左右就会性能崩溃。如果有依赖这个特性的，请大家注意有可能会引起整体系统的性能雪崩。