记一次store 指标库 线上故障的排查

目录 (Table of Contents)

环境

统计局,三个节点配置一样:

  • 内存:500+G
  • CPU:4*13 core

Cassandra 、kaiorsdb 、指标库都是以集群模式部署在三台机器上。

问题&分析&解决

问题1

统计局 monitor线上环境 统计报表和仪表盘部分加载缓慢,加载时间在8秒左右。

分析

首先看了指标库的reader 模块日志,发现query 大量timeout异常。

1
2
17-09-22 14:12:29.208 WARN  [DubboServerHandler-10.6.143.124:7513-thread-576] [c.a.d.rpc.filter.TimeoutFilter]  [DUBBO] invoke time out. method: queryarguments: [e10adc3949ba59abbe56e057f20f88dd, DatapointQuery{metric='system.mem.pct_usage', time=DatapointQueryTime{start=1506060435275, end=1506060735275, interval=1, interval_unit='seconds', aggregator=AVG, align_start_time=false, align_sampling=false}, tags={tenantId=e10adc3949ba59abbe56e057f20f88dd}, groupBy=DatapointQueryGroupBy{tagKeys=[object]}, useCache=false}] , url is dubbo://10.6.143.124:7513/uyun.indian.reader.api.ReaderService?anyhost=true&application=indian-reader&default.accepts=1000&default.threadpool=cached&default.threads=500&default.timeout=5000&dubbo=2.8.4.170831&generic=false&interface=uyun.indian.reader.api.ReaderService&methods=queryByResId,query,queryAllMetrics,queryTags&pid=20707&revision=api&serialization=kryo&side=provider&timestamp=1505982696415, invoke elapsed 6361 ms., dubbo version: 2.8.4.170831, current host: 10.6.143.124
17-09-22 14:13:00.201 WARN [DubboServerHandler-10.6.143.124:7513-thread-568] [c.a.d.rpc.filter.TimeoutFilter] [DUBBO] invoke time out. method: queryAllMetricsarguments: [e10adc3949ba59abbe56e057f20f88dd] , url is dubbo://10.6.143.124:7513/uyun.indian.reader.api.ReaderService?anyhost=true&application=indian-reader&default.accepts=1000&default.threadpool=cached&default.threads=500&default.timeout=5000&dubbo=2.8.4.170831&generic=false&interface=uyun.indian.reader.api.ReaderService&methods=queryByResId,query,queryAllMetrics,queryTags&pid=20707&revision=api&serialization=kryo&side=provider&timestamp=1505982696415, invoke elapsed 6939 ms., dubbo version: 2.8.4.170831, current host: 10.6.143.124

解决

query 使用的 kairosdb的读方法。kairosdb wiki上指出,当指标的 tag/value 组合太大时,查询时将变得非常缓慢。
而monitor报表 每次查询需要汇聚一天的数据。一天的指标数据量和读取时间如下:

一种解决方法是使用TScached进行读取,tscached 是kairosdb 的一个缓存代理,加载速度可以是kairosdb的100倍(这是它自己说的,感觉有点夸张了)。
指标库之前已经配置过 TScached,后来停用了。重新启用后,报表的加载速度明显加快,不再报超时。

1
2
3
4
5
6
7
8
17-09-28 10:01:26.123 INFO  [reporter-thread-1   ] [u.i.method.elapsedtime.report ] ********************* start report 2017-09-28 09:56:26 to 2017-09-28 10:01:26 *********************
17-09-28 10:01:26.131 INFO [reporter-thread-1 ] [u.i.method.elapsedtime.report ] methodName=uyun.indian.reader.impl.KairosdbReader, count=320, min=16ms, max=1496ms, avg=116.33ms, median=66.00ms, p75=156.00ms, p95=278.95ms, p99=889.79ms
17-09-28 10:01:26.133 INFO [reporter-thread-1 ] [u.i.method.elapsedtime.report ] methodName=uyun.indian.reader.impl.ReaderServiceImpl.query, count=592, min=16ms, max=1732ms, avg=105.24ms, median=62.00ms, p75=105.00ms, p95=276.05ms, p99=936.27ms
17-09-28 10:01:26.133 INFO [reporter-thread-1 ] [u.i.method.elapsedtime.report ] methodName=uyun.indian.reader.impl.ReaderServiceImpl.queryAllMetrics, count=1, min=4ms, max=4ms, avg=4.00ms, median=4.00ms, p75=4.00ms, p95=4.00ms, p99=4.00ms
17-09-28 10:01:26.134 INFO [reporter-thread-1 ] [u.i.method.elapsedtime.report ] methodName=uyun.indian.reader.impl.ReaderServiceImpl.queryByResId, count=2, min=2ms, max=40ms, avg=21.00ms, median=21.00ms, p75=40.00ms, p95=40.00ms, p99=40.00ms
17-09-28 10:01:26.134 INFO [reporter-thread-1 ] [u.i.method.elapsedtime.report ] methodName=uyun.indian.reader.impl.ReaderServiceImpl.queryTags, count=4, min=37ms, max=38ms, avg=37.50ms, median=37.50ms, p75=38.00ms, p95=38.00ms, p99=38.00ms
17-09-28 10:01:26.135 INFO [reporter-thread-1 ] [u.i.method.elapsedtime.report ] methodName=uyun.indian.reader.impl.TScachedReader, count=272, min=22ms, max=1732ms, avg=91.88ms, median=57.00ms, p75=75.75ms, p95=241.05ms, p99=1092.88ms
17-09-28 10:01:26.135 INFO [reporter-thread-1 ] [u.i.method.elapsedtime.report ] ********************* end report *********************

问题2

query 方法速度上来之后,发现queryAllMetrics 方法出现超时现象,按问题1的解决办法处理后,发现仍有问题,后改用读redis 缓存的方式后,暂时解决。
但Cassandra的资源消耗仍比较大

分析

查看Cassandra system日志后发现 kairosdb.data_points 表中存在大量tombstone(墓碑)数据警告,严重影响了Cassandra性能。需对Cassandra 进行数据compact(压实)操作,以清除墓碑数据。
在对数据进行压实操作之前,需要先repair(修复)。

1
WARN  [SharedPool-Worker-30] 2017-09-26 15:48:50,818 ReadCommand.java:481 - Read 1024 live rows and 22072 tombstone cells for query SELECT value FROM kairosdb.data_points WHERE key = 65313061646333393439626135396162626535366530353766323066383864647e73797374656d2e6e65742e62797465735f72637664000000015dc970d000000d6b6169726f735f646f75626c656465766963653d6962313a686f73743d646d3031646261646d30342e73746174732e676f762e636e3a69703d31302e362e3133342e38303a6f626a6563743d3539383763643931633633396438613830633433653631383a74656e616e7449643d65313061646333393439626135396162626535366530353766323066383864643a AND column1 >= 00000000 AND column1 <= 9dd94 (see tombstone_warn_threshold)

在Cassandra中,一切都是写入,包括逻辑删除数据,当你删除一条数据时,其实是给这条数据进行update,给它update上一个标识,就是一个墓碑标识。 当Cassandra集群在不同节点之间同步删除信息的时候,也会用到Tombstones(墓碑),可以说墓碑是一种允许Cassandra快速写入的机制。

关于Cassandra 如何维护数据,可参考 Cassandra 数据维护官方文档

解决

具体压实步骤如下:

  1. cassandra 默认压缩周期为10天,首先将压缩周期设为1天,设置 gc_grace_seconds 参数,

登录Cassandra:

1
./cqlsh host -u user -p pswd

设置kairosdb的表的压缩周期设为 一天(86400 s):

1
2
3
4
5
alter table kairosdb.string_index with gc_grace_seconds = 86400;alter table kairosdb.data_points with GC_GRACE_SECONDS = 86400;alter table kairosdb.row_key_index with GC_GRACE_SECONDS = 86400;

```

设置完后 ,运行`DESC kairosdb;`,可以看到 **gc_grace_seconds**已被设为86400;

CREATE TABLE kairosdb.string_index (
key blob,
column1 text,
value blob,
PRIMARY KEY (key, column1)
) WITH COMPACT STORAGE
AND CLUSTERING ORDER BY (column1 ASC)
AND bloom_filter_fp_chance = 0.01
AND caching = {‘keys’: ‘ALL’, ‘rows_per_partition’: ‘NONE’}
AND comment = ‘’
AND compaction = {‘class’: ‘org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy’, ‘max_threshold’: ‘32’, ‘min_threshold’: ‘4’}
AND compression = {‘chunk_length_in_kb’: ‘64’, ‘class’: ‘org.apache.cassandra.io.compress.LZ4Compressor’}
AND crc_check_chance = 1.0
AND dclocal_read_repair_chance = 0.1
AND default_time_to_live = 0
AND gc_grace_seconds = 86400
AND max_index_interval = 2048
AND memtable_flush_period_in_ms = 0
AND min_index_interval = 128
AND read_repair_chance = 1.0
AND speculative_retry = ‘NONE’;

1
2
3


2. 为了统一各个节点的墓碑数据,需在各个节点上分别运行修复kairosdb下各个表,防止已删除数据重生;

nodetool repair kairosdb row_key_index
nodetool repair kairosdb string_index
nodetool repair kairosdb data_points

1
2
3
4

*此处运行修复时,三个节点的data_points表由于数据太大,一直没有完全修复成功(some repair failed )。由于数据量较大,且接受删掉的数据再次恢复,此处采取的措施是忽略该表。

3. 修复完后再分别进行压实操作:

nodetool compact kairosdb row_key_index
nodetool compact kairosdb string_index
nodetool compact kairosdb data_points

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
 
压实操作可用`nodetool compactionstats` 和 `nodetool compactionhistory`分别查看当前和历史的压实造作;

{% asset_img compactionstats.png 压实状态 %}

4. 开启自动压实操作(默认已开启):`nodetool enableautocompaction`

操作完后,Cassandra 会自动压缩一些其他表的数据。结束后,Cassandra 日志中data_points表 墓碑警告记录墓碑数量大幅变小,可以发现Cassandra对资源的占用变到正常水平。


#### 其他问题

1. cassandra 日志报:

``
INFO [IndexSummaryManager:1] 2017-09-28 08:16:56,278 IndexSummaryRedistribution.java:74 - Redistributing index summaries
INFO [SharedPool-Worker-1] 2017-09-28 08:19:46,973 NoSpamLogger.java:91 - Maximum memory usage reached (536870912 bytes), cannot allocate chunk of 1048576 bytes
``

2. Dubbo 消费者报:No provider available for the service。


#### 分析&解决

1. 调查得知,原因是file_cache_size_in_mb较小,文档中描述该参数是用来读[SSTables](https://stackoverflow.com/questions/2576012/what-is-an-sstable)(Sorted Strings Table , is a file of key/value string pairs, sorted by keys)的缓冲区:
>file_cache_size_in_mb :(Default: Smaller of 1/4 heap or 512) Total memory to use for SSTable-reading buffers.

调到1024 (M)后,不再报该问题

2. 服务注册不到zookeeper 上,猜测可能是机器IO负载太大。
执行`netstat -nat | awk '{print $6}' | sort | uniq -c | sort -n` ,可以看到 CLOSE_WAIT 连接太多:

[root@Uyun-DB2 logs]# netstat -nat | awk ‘{print $6}’ | sort | uniq -c | sort -n
1 established)
1 Foreign
2 TIME_WAIT
47 LISTEN
1088 ESTABLISHED
3314 CLOSE_WAIT
`

netstat -nat | grep CLOSE_WAIT 后,发现是kairosdb 造成的(猜测是之前Cassandra负载太大造成 ),强行重启kairosdb 后,再启动指标库,服务正常。

其他

  1. kairosDB 作者建议采用DateTieredCompactionStrategy (DTCS)压实策略,参考 kairosDB Issue 23。需要进一步研究。

  2. 还是会有 Cassandra 占CPU较高的现象,但日志正常,需要进一步研究。

资料

Cassandra–How is data maintained

操作Cassandra(3)-合并、压实

Cassandra 的压缩策略STCS,LCS 和 DTCS