logstash消费kafka数据慢 logstash无法消费kafka数据

转载

mob64ca14116c53 2024-02-16 11:44:42

文章标签 logstash消费kafka数据慢 elasticsearch kafka 数据 文章分类 架构后端开发

最近遇到一个新的问题，当使用filebeat加载历史日志文件的时候，大量的数据会被加入到kafka队列，logstash会从队列里面读取大量的event发送到ES端。最开始的表现形式是：
logstash一直不断的往ES发送信息，ES里面的数据也一直在增加，日志的写入量远大于原始的日志量，并且没有停止的迹象。
经查看kafka的consumer checker，发现队列的offset一直没有发生偏移。即kafka一直没有得到logstash的消费确认，认为消息一直没有被消费。我们知道，在整个ELK的流程中，logstash的input从kafka上取数据，经由filter，output插件，发到ES，只有ES返回成功之后，logstash才会更新kakfa的offset，如果ES返回失败，则logstash不会更新kafka的offset，并会尝试重新发送消息，值到成功为止。这个问题在我们这里引起了严重的问题，即kakfka里面的消息一直没有被消费，logstash一直在重试，但实际上数据却已经插入到了ES当中，导致ES的index不停增大，system load evarage一直在增大，响应更慢。

这个问题的发现，需要打开logstash的debug log (在logstash.yml文件里面加入)：

log.level: info

这时，在log里面会发现类似的打印：

[ERROR][logstash.outputs.elasticsearch] Retrying individual actions
[INFO ] [logstash.outputs.elasticsearch] retrying failed action with response code: 429 ({"type"=>"**es_rejected_execution_exception**", "reason"=>"rejected execution of org.elasticsearch.transport.TransportService$7@742302a0 on EsThreadPoolExecutor[bulk, queue capacity = 200, org.elasticsearch.common.util.concurrent.EsThreadPoolExecutor@6ae23e0c[Running, pool size = 8, active threads = 8, queued tasks = 206, completed tasks = 5502508]]"})
[ERROR][logstash.outputs.elasticsearch] Attempted to send a bulk request to elasticsearch' but Elasticsearch appears to be unreachable or down! {:error_message=>"Elasticsearch Unreachable: [http://elastic:xxxxxx@10.60.33.105:9200/][Manticore::SocketTimeout] Read timed out", :class=>"LogStash::Outputs::ElasticSearch::HttpClient::Pool::HostUnreachableError", :will_retry_in_seconds=>2}

elasticsearch的REST API若返回状态代码429({“type”=>”es_rejected_execution_exception“, “reason”=>”rejected execution of org.elasticsearch.transport.TransportService)，这意味着ES已经没法再处理新进的消息了（ES cluster is not able to keep up with the incoming requests, ）
同时，通过x-pack查看ES集群的运行状态：

发现，虽然CPU的使用率只有60%，但系统的load average已经达到10，代表系统已经是在1.2倍负荷的状态下运行。（服务器是8核，2.2G的主频）
(在多处理器系统中，负载均值是基于内核的数量决定的。以 100% 负载计算，1.00 表示单个处理器，而 2.00 则说明有两个双处理器，那么 4.00 就说明主机具有四个处理器)

这个说明什么情况？因为CPU的使用率并不是特别高，但系统的负载却很高，我们猜测系统的主要负载是在io上。再返回来观察logstash的log:

[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Retrying individual actions
[2017-07-10T11:17:02,084][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action
[2017-07-10T11:17:02,085][ERROR][logstash.outputs.elasticsearch] Action

我们发现，在很多的时间内，反复提示429的错误，代表logstash在不断的，快速的给ES发送bulk reuqest。我们查看logstash的配置发现，默认的配置是：

# How many events to retrieve from inputs before sending to filters+workers#
pipeline.batch.size: 125
## How long to wait before dispatching an undersized batch to filters+workers# Value is in milliseconds.#
pipeline.batch.delay: 5

这里的单位是milliseconds，即每个logstash的instance，每秒会发送200条request到ES集群，这个会导致ES集群的网络io过载

那么，是不是说我们需要把每个batch之间的间隔缩短，把每次batch的size调大？比如batch.size = 1500, batch.delay = 500，已防止出现429的问题？
经过测试，这样是可行的。

但为什么ES的集群会在200 bulk request的情况下会报错？随便一个web server都不会处理不了200条request吧？
查了一下ES的配置文档，发现少配了个数据，具体是vi /etc/security/limits.conf：