最近遇到2个线上问题,记录一下,总结经验。
有业务反馈线上服务有时候查询不出来结果,自己用业务反馈的请求,试了几次果真会出现查询不到的问题。
先说一下我们的整体架构,最上层是vip,负责负载均衡和机器谈话,中间是proxy,底层才是实际的存储服务节点。
排查过程:
图1:
我们可以看到3次握手成功以后,客户端36972端口发送了一个请求,服务端3028端口回报了,但是回报的seq号和前面不连续。
3次握手里面3028端口发送的seq是4072672142,但是看3028端口回的数据包的seq是4022679883,明显中间有丢包了。当然有可能是tcpdump抓包的时候丢的。
图2:
看图中的红框,出现了tcp经典的200ms重传。验证了图1所说的丢包问题。图1和图2,端口对不上的原因是中间还有一层vip服务。
最后解释一下原因:
mss值会取客户端和服务器之间的最小值,mtu为1600机器之间协商出来的mss大小1540,mtu1500和mtu1600机器协商是1440。
所以2台mtu1600之间传输大包的时候会在vip机器进行分片,分片之后的包没有4层头信息,所以没办法顺利转发,出现丢包现象。
不知道这算不算vip的问题,在tcp3次握手的时候,没有把本机的mtu值传给通信双方。
某天组内同事服务的时候,发现有一台机器突然出现出core,其他机器正常,而且诡异的是出core是另外的服务,和本次升级服务,没有任务逻辑关系。
排查过程:
2019年最后一篇文章,今天来说一下rocksdb里面文件删除相关逻辑。rocksdb的多版本key存在,决定了需要gc功能,这就少不了删除文件。
主要删除文件有2个地方:
为了保证数据不丢失,wal文件删除必须在flush memtable以后操作。
先说一下哪些条件会触发flush:
SwitchMemtable函数会判断是否需要创建新的wal文件,依据是当前的wal文件是否为空,为空的就复用。否则就创建新文件
新文件会append到logs_和alive_log_files_这2个数据结构里面。
先来说一下这2个数据结构:他们保存的都是活跃wal文件,好像除了2pc场景以后,没有区别,有知道的朋友可以告诉我。
每个ColumnFamily(简称cf)都会存储自己的最小log文件号,当flush memtable以后会更新这个文件号
每个memtable可以对应多个wal文件,原因是memtable没有写满,可能其他cf正在做switchmemtable。
这个函数的功能是扫描需要删除的文件,然后交给PurgeObsoleteFiles删除。如果rocksdb构建checkpoint的时候,会在这个函数里面直接return。
这个函数会在全局锁的保护范围内,所以这个函数不能做太重的事情,否则会影响rocksdb的读写性能
rocksdb默认6个小时会扫描db的全量文件,这个全局扫描在文件数特别多场景下会有性能问题。
下图是写了一个简单c程序扫描目录文件统计耗时:
可以看到当文件数达到百万级别的时候耗时就非常大了,所以不推荐单个rocksdb存储特别多的数据,当然可以通过调整文件大小来减少文件数,但是这样做也会有其他的性能问题。
至于FindObsoleteFiles函数为什么要全量扫描文件,我想这块更多的是为了防止代码出现bug导致文件不能被删除。
同时在这个函数里面会获取每个cf最小的log文件号,然后判断logs_和alive_log_files_里面是否有文件需要删除。
这个函数会二次校验文件是否可以删除,同时也支持异步删除。
迭代器释放的时候会调用这个函数释放资源,比如说删除sst文件。
可以设置background_purge_on_iterator_cleanup=true异步的释放资源,减少阻塞用户请求时间
具体的调用逻辑看下图:
LSM树的结构是MVCC多版本存在,这种结构非常方便快速导入数据文件。新数据事先合并成底层存储文件,通过接口直接导入,读取的时候优先读取新数据就可以保证数据准确性。Hbase也是LSM树结构,它具备blukload 快速导入数据功能。rocksdb同样也具有这个功能。今天研究一下rocksdb是怎么实现这个功能的。
virtual Status IngestExternalFile(
ColumnFamilyHandle* column_family,
const std::vector<std::string>& external_files,
const IngestExternalFileOptions& ingestion_options) override;
使用IngestExternalFile接口,参数是column_family, 文件名和options就可以导入文件到db中,使用方式很简单。
重点看一下option里面有哪些配置项
// IngestExternalFileOptions is used by IngestExternalFile()
struct IngestExternalFileOptions {
//导入文件和rocksdb数据目录在同一个文件系统的时候,一般设置为true
bool move_files = false;
// 设置为true,可以保证导入的key的seq比db中已有的快照都大
bool snapshot_consistency = true;
// 如果设置false,文件自带的seq不能用的时候,那么直接返回导入失败
bool allow_global_seqno = true;
// 如果设置false,导入的文件如果和memtable有overlap,那么直接返回导入失败
bool allow_blocking_flush = true;
// 如果设置为true,那么会把文件导入到最低层level,前提是和已有文件范围不冲突,冲突就返回导入失败,适合空db初始化导入数据
bool ingest_behind = false;
//设置为true,会打开导入的sst文件,然后修改seq号,这个参数涉及到版本兼容问题,rocksdb未来会设置默认false
bool write_global_seqno = true;
//设置为true,会打开每个导入文件,对每个block进行crc校验,会影响导入速度
bool verify_checksums_before_ingest = false;
};
对于一个空的db,全量导入数据的时候,可以所有的sst文件的seq都是0。ingest_behind可以设置为true,write_global_seqno设置false
最近在facebook看到有人提问,学习到了新参数:periodic_compaction_seconds。这个参数的作用是:强制把某个时间点以前的sst文件重新compact,比如说7天以前生成的sst文件。对应的还有其他类型的compaction:ttl compaction, bottommost file compaction, marked file compaction。下面详细介绍一下这几个具体的用处
如果我们设置了全局ttl过期时间,并且最底层的sst文件范围区间里面并没有读写,那么这部分数据是很难被删除掉的,白白占用了磁盘空间。如果我们触发manual compact的话,会导致compact范围太大,增加磁盘io压力,对读写性能都有比较大的影响。我们可以设置periodic_compaction_seconds这个参数等于全局ttl过期时间,这样能及时的删除过期数据,同时又不会增加io压力。
ttl和periodic_compaction_seconds区别是,ttl compaction不选择最底层sst文件, 感觉可以不需要这个参数
bottommost file compaction只选择最底层的sst文件,并且文件中有delete key,同时没有快照依赖最低层sst文件。不考虑snapshot,本身compact生成的最底层文件里面是不带delete key,在compact过程中,直接丢弃delete key。但是如果有snapshot的存在就可能会导致delete key和原来的真实key/value不能被compact丢弃。本来最底层sst文件被compact的次数就比较少,如果这种情况出现多了,会导致seek性能变差,以及存储空间放大。bottommost file compaction可以有效的解决这个问题。
用户可以主动设置策略标识compact哪些文件。我们知道delete key多了以后,会影响rocksdb的读性能,那么我们可以设置优先compact 包含delete key多的文件,参考CompactOnDeletionCollector。
CompactOnDeletionCollector构造函数只有2个参数:sliding_window_size和deletion_trigger。就是说如果在window_size里面delete key个数超过了deletion_trigger,那么就会把这个sst文件标识为need compaction。
这个滑动窗口实现还是挺有意思的,比如说我们设置窗口大小256,deletion_trigger=16。我们最简单的实现是每256个key,重新计数delete key个数,这样朴素方法无法统计分区临界点数据,比如说前一个窗口末尾有10个delete key,后一个窗口开头有10个delete key,这种场景是不能被标识处理。想要精确统计的话,我们可以申请一个window_size大小的循环数组,每key都映射到数组里面的一个元素,然后每次更新数组以后,都统计一下数组里面当前的delete key数量。rocksdb采用了折中方法,申请了128大小的循环数组,bucket_size = window_size / 128, bucket_size个元素对应到循环数组里面一个元素。
每次compact生成新的文件的时候都会判断新文件是否需要need compaction。在LOG里面会打印类似信息:
2019/10/09-16:44:28.062404 7f3ba931b700 [db/compaction_job.cc:1133] [default] [JOB 4202] Generated table #27486121: 430042 keys, 135440918 bytes (need compaction)
对于基础存储服务来说,性能是至关重要的,偶尔的抖动都会在业务层放大很多倍。linux perf工具可以帮助我们定位服务热点和瓶颈。对于LSM树,天然存在读写放大的问题,可能一次读操作,需要多次io才能找到我们想要的数据。对于这种情况,外部工具并不方便观察,rocksdb自带的perf工具可以详细的输出各种路径上的操作次数和耗时。
get_perf_context()->Reset();
your code
print get_perf_context()->ToString()
输出的内容很多,有key的比较次数,block_cache命中次数等,可以根据输出内容分析出数据是来自于memtable, 还是block cache读取还是磁盘读取, 还可以分析出操作耗时,比如说在memtable上seek耗时和get耗时。耗时统计这个地方也很巧妙,构造了临时对象,析构的时候会调用stop函数,统计耗时
class PerfStepTimer {
public:
~PerfStepTimer() {
Stop();
}
}
// Declare and set start time of the timer
#define PERF_TIMER_GUARD(metric) \
PerfStepTimer perf_step_timer_##metric(&(perf_context.metric)); \
perf_step_timer_##metric.Start();
另外还有一个观察磁盘读写的监控,使用方法也是和上面类似
get_iostats_context()->Reset();
your code
print get_iostats_context()->ToString();
可以观察一次put/get操作,实际底层的磁盘读写情况,put操作大概率观察不到,因为数据一般先写到内存buffer(写wal也是这样),除非配置了direct_IO模式。
我们的分布式存储服务最上层是用go写的proxy,负责路由分发。最新加了一些新功能以后发现,偶尔出现100毫秒以上的大毛刺。 但是对应存储节点并没有出现大毛刺,毛刺耗时消耗在哪里?不会又是网络问题吧。统计毛刺的日志,发现并没有出现规律。 于是采用最笨的方法,小流量一台proxy,增加耗时统计日志,看看到底耗时消耗在哪里。通过日志发现了毛刺出现的时候主要耗时并不固定在一个地方。同时发现很简单的代码居然也能出现100毫秒的超时。代码如下:
usnow := data.Microseconds()
tracelog := &data.ReqTraceLog{
RemoteAddr: c.Sock.RemoteAddr().String(),
LastRecordUs: usnow,
Start: usnow,
}
cmd := query[0]
sql := query[1:]
r := &data.Request{
Start: usnow,
Wait: &sync.WaitGroup{},
TraceLog: tracelog,
Sql: sql,
Index: -1,
}
usnow2 := data.Microseconds()
r.TraceLog.RecordTimeWithoutCollect2("buid request cost", usnow2 - usnow)
上面这段代码就是简单的构建对象,并没有复杂操作,这让我感到非常困惑。好在go的相关工具非常全,代码里面引用了net/http/pprof包,这非常方便查看相关数据。
先通过/debug/vars接口看下大概的情况,打印出来发现PauseNs有非常大的值,关于这个值详细说明可以参考godoc,大致说一下PauseNs是一个固定大小为256的循环数组,记录最近的gc时间,数组里面一个元素表示一次gc耗时。虽然go的gc功能已经有所优化,但是还是会有stop world现象。同时观察PauseEnd数组,和PauseNs是对应的,记录每次gc的时间戳,刚好和我们出现毛刺的日志能对应上,说明毛刺的原因是gc导致。那么目标就很明确,优化内存使用。
首页使用go tool pprof -alloc_space -cum -svg http://addr/debug/pprof/heap > heap.svg, 生成内存申请图,用chrome浏览器打开,可以查看哪些函数分配的内存比较多。 目标就是优化内存申请。
图中线条越粗说明内存申请越多,可以看到主要消耗在读包,解包和回包,仔细查看代码发现,对于短链接情况,每个连接都会申请对象接收包,自然想到的优化就是使用pool存储对象,回收的时候不直接gc,放到pool供后续链接复用。对于解包的代码,函数调用链比较长,中间会申请很多临时buffer,可以一开始申请大块buffer,然后都在大buffer里面分配内存,不用再向系统申请,回收的时候也统一释放。对于回包的代码也做同样的优化,申请大块buffer,在大buffer里面分配内存。 优化以后内存申请图 看监控效果图
黄色的线是优化之后的,内存使用在平常情况已经下降了很多,但是还是会出现内存突然上涨的情况,时间和PauseEnd能对应。
继续分析内存申请图,发现查询索引的地方申请内存很多。想到的方法就是使用内存池 下面是使用sync.Pool实现的。
BytePool = &sync.Pool{
New: func() interface{} {
b := make([]byte, 0, 64)
return &b
},
}
prefix := BytePool.Get().(*[]byte)
defer BytePool.Put(prefix)
使用过程遇到2个坑
golang中申请变量,用户是不知道变量在堆上还在栈上,编译器自己优化判断,在堆上面申请很多对象的时候会影响gc耗时。我们可以在编译的时候增加参数分析内存逃逸情况。-l 是禁止内联 -m 分析内存逃逸,最多提供4个-m,一般2个就够用了。使用方法:
go build -gcflags '-m -m -l' main.go
但是对于整个工程来说,没有找到内存逃逸分析的方法,如果有知道的同学,可以分享我一下。 感兴趣的同学可以搜索Golang escape analysis可以查到很多资料