前言
这次是慢查询的故事,一些情况下很难避免,我们屏蔽来源,只讨论量。从最开始只要简单处理能过滤报警(几百),坏个盘也就是这么量。到小 Region灰度,单Client 峰值8K,再到大集群单 Client 峰值几万,程序一路翻车。
对于报警而言,我们更关注各个来源每秒可以处理的量,总体意义不大,数据来源主要为双机压测结果(非Server吞吐量,且包含网络请求耗时)。
一些环境下是不存也不方便引入其他中间件的,一个Centos7 自带的 Python 2.7.5 一路黑到底。
项目不同阶段
日常需求阶段(几百)
慢查询有一定格式,我们简单抽象为 A 和 B,其中含义如下:
A: 检测到一个查询还没结束,无法判定,因此记录到日志中
B: 检测到一个很耗时的查询,并且已结束,记录到日志中
因此常见组合方式为:
- AA...AB (多次受到慢查询存在告警,最后受到结束告警)
- B (刚好检测到一个耗时的查询,并且已结束)
- A...A (异常情况)
消息消费大致是B已完成,需要实时处理,A则需要抑制并判断阈值在报警,因此可以将服务分为 Server 和 Client:
Client 读取日志,记录 Offset,过滤无效日志,发送成功则刷新 Offset,否则暂停读取,重发。
Server则分为Master 和 Monitor,Master处理实时数据,其他的写入文件,完成就返回,剩下由有Monitor 消费,由此借助文件实现跨进程通信,以及消息实时落盘。(消息生成主键,因此重复写不影响,Monitor 读取时候直接去重即可。)
有很多成熟文件DB,简单的操作背后都是时延增大,本文是直接读写文件。因写文件而速成,也会因文件也受限。
多客户端冲突期
第一版有个很大的竞争点,就是所有消息公用一个文件作为跨进程通信与落盘。因此多客户端已接入,立马互相竞争文件锁,性能瞬间只剩几十,惨不忍睹。
提示:一个 Region 两台统计点,日志是随机打过去的,因此采用放在同一个文件进行比对。当然这是不合理的,当对同一个消息AB很短时间间隔内到达两个节点。再经过采集合并发送到报警服务器,基本无法保证有序。这个阶段已调整,单节点保序。
按 Client 分消息队列,就是分文件了,性能又恢复了。
小故障爆发期(几千,比如2-3千)
这个时候就是把以前偷的懒都给补上了,当然不是每个思路都有效,比较有效的有:
- 各类批量操作: 批量写消息、批量查数据库等
- 更换序列化,比如由 Json 改为 Marshal
- 优化时间格式处理, 自带的 strptime 性能很差,可以小用 panda
- cache,集群、节点等相关属性变化很低,适合放内存
替换实现是一个系统活,有一些测压对比统计,可以供大家参考,真正有提升在替换。
包 | 内置 | 单条序列化长度 | 1K列表序列化长度 | 单条1W次 dumps | 单条1W次 loads | 单次1K条 dumps | 单次1K条 loads |
json | 是 | 754 | 771393 | 0.1193 | 0.2423 | 0.0095 | 0.0402 |
pickle | 是 | 975 | 318576 | 1.8495 | 1.6626 | 0.1121 | 0.0681 |
marshal | 是 | 791 | 495263 | 0.0505 | 0.0606 | 0.0026 | 0.0039 |
ujson | 否 | 698 | 712394 | 0.0451 | 0.0597 | 0.0048 | 0.0105 |
msgpack | 否 | 629 | 640259 | 1.5178 | 2.6460 | 0.1622 | 0.4593 |
marshal 是不安全的,不通用的,不同版本也不兼容的。不过这速度,又是内网环境,我最终义无反顾选择了它。
插入一个无效的优化手段,乍一看我是认为有效的。来个简单常见,就是消息记录,然后按 A、B分类,参考代码如下:
def cls_message(handler, raws):
"""对日志分类,然后简单格式化下"""
logger = logging.getLogger(handler)
slow_dict = {}
pending_dict = {}
for message in raws:
key = make_key(message)
if message.get('flag') == 'Pending':
pending_dict[key] = formatter(message)
logger.debug("save client Pending message <%s> success!" % key)
elif message.get('flag') == 'Slow':
slow_dict[key] = formatter(message)
logger.debug("got client slow message <%s>" % key)
else:
logger.warning("Message flag %s not define" % message.get('flag'))
这个坑在多客户端就已经出现了,因为多进程写日志,采用文件锁。多客户端同时写,大家应该能猜到,效果就看表格吧。
场景(2000条) | 耗时 |
不打日志 | 0.002063274383544922 |
单线程打日志 | 0.12387228012084961 |
多线程打日志(4) | 0.4494140148162842 |
多进程打日志(4) | 36.29296827316284 |
偷懒点,可以直接关闭细节日志。深入思考也可以看出,单线程性能是牛逼的,不过为了写日志,上下文切换,性能直接降低近百倍。采用多线程,性能在降几倍,说明这种场景下,线程切换开销大于收益。而多进程受限于原先使用的文件锁,不太适合比较。
分布式实时报警(几万)
当各类优化到极致,细节日志都关掉,这样单实例的瓶颈已经出现了,很难在大幅度提升了。而基于文件的跨进程通信也是一个很慢的效率,CPU 密集型的 多线程也不会有效果,多进程创建销毁开销也很大,基本不太适用这种场景。因此基于 socket 的并行内存实时计算,可以预见是一个简单有效的方法。抽象下基础服务,我们大致需要如下:
- Master 服务,接收 Client 信息,然后转发给指定 Consumer 服务
- Consumer服务,只接收指定来源信息,消息独立而有序,避免跨进程内存共享
- LogServer服务,日志统一接收处理,提高效率,也方便排查问题。
- Monitor服务,对符合条件消息,进行报警
服务拆分好,接着选 RPC 了,可以直接 Socket 封装,也可以使用已有的。当前 LogServer 采用Socket 通信,因为 logging 自带客户端,只需要实现服务端就可以了。
场景(2000条) | 耗时 |
单线程写 socket 日志 | 0.11522245407104492 |
其他的采用 Zeromq,这个性能与Socket一样,不过使用更方便,为了支持多客户端同时请求,才用了 ROUTER - DEALER 作为通信框架,参考了 locust_rpc 实现,简单易用。
关于消息拆分粒度,我也做了个尝试,就是Master 接收到消息后,在按保序前提下分为 M 块,然后发送个 M 个Consumer,结果速度反而更慢了。我总结了下消耗:
虽然 Consumer 变快了,但是路径更长了,速度反而更慢了
进入内存计算后,关于如何不丢失日志,我其实困惑了一段时间。
方案一、预写日志。Consumer 收到消息,先写日志,在处理。这样又有新问题,比如网络不好,Client 未收到指定码触发重发,那么如何实现日志回滚?第二就是运行很长一段时间,一旦重启,这加载速度也太慢了。
方案二、快照。这个好理解,缺点不及时?相对于预写日志,每条都写。然而真是这样吗?
再回到方案一的问题,是不是负负得正,一的问题不就是二的答案吗!
因为最近一直优化细节,反而忘记了整体,在最初设计中,为了保证数据不丢失,我们设计的原子操作是每次请求,而不是每条日志!跳出每次日志的来看,直接对每次请求执行快照,不就可以保证数据不丢失了。而覆盖写单次效率很不错,参考数据如下:
类型 | 次数 | 单次大小 | 虚拟机(三次) |
覆盖写 | 1000 | 1024 | 0.12、0.12、0.13 |
覆盖写 | 1000 | 1024 * 4 | 0.12、0.11、0.13 |
覆盖写 | 1000 | 1024 * 10 | 0.14、0.13、0.16 |
覆盖写 | 1000 | 1024 * 1000 | 2.1、2.2、1.8 |
Consumer 初始化的时候加载快照,之后每次消息过来,都在内存中计算。计算完毕,触发一次快照覆盖,然后返回 Master,失败返回异常码,则重发再来。
支持更大并发
考虑到在 Master 端进行数据在分割并没有效果,那么把 Client 包含进来,当做一个整体看待。正常按行读日志,效率也够了。毕竟写日志的上限在那里摆着,不用过度优化。不过日志格式转化是个CPU密集型任务,是可以通过 RPC 改为并行计算,顺带也实现了数据分片,简单的实现更高并发。
优化总结:在数据流向路径不变的情况,优化原先模块或者拆分为并行计算,效果会很明显;反之为了并行而增大路径,额外增加的序列化成本,以及并行开销可能导致速度更慢。
参考文献:
zmq_rpc: https://github.com/locustio/locust/tree/master/locust/rpc