Kafka客户端报错MESSAGE_TOO_LARGE

其实我有点犹豫要不要写这个文章,因为笔者的kafka客户端版本并不是最新的,不知道新版本是否会有这个问题。

版本提示

kafka server版本

Scala 2.11 - kafka_2.11-2.0.0.tgz

kafka client版本

<dependency>
    <groupId>org.springframework.kafka</groupId>
    <artifactId>spring-kafka</artifactId>
    <version>2.1.7.RELEASE</version>
</dependency>
<dependency>
    <groupId>org.apache.kafka</groupId>
    <artifactId>kafka-clients</artifactId>
    <version>1.1.1</version>
</dependency>

问题现象

笔者在优化公司kafka producer性能时发现一个很奇怪的现象,当 1000tps 从外部输入消息给kafka producer的时候,即每秒1000个record,但实际上会发现kafka.producer:type=producer-metrics mbean的record-send-rate会达到14000到15000r/s,record-error-rate会达到1000r/s。因为配置了batch.size为5MB和linger.ms为5秒,所以消息是会缓冲一段时间发送出去的,但是不至于能长时间持续积攒出每秒1万多的记录,这样大的发送速度发下去,也没消息能积攒下来啊。

我发现kafka客户端的日志没有打印,于是配置了org.apache.kafka.clients logger, 日志级别设置为TRACE

我在日志中发现了下面的报错,关键词是MESSAGE_TOO_LARGE

2020-05-14 21:29:58.624 [kafka-producer-network-thread | producer-1] WARN (org.apache.kafka.clients.producer.internals.Sender:509) completeBatch - [Producer clientId=producer-1] Got error produce response in correlation id 226233 on topic-partition span-1, splitting and retrying (3 attempts left). Error: MESSAGE_TOO_LARGE

后续还试过batch.size设置为1MB,也是一样的现象,凭空多出很多消息的感觉。

首次确定报错含义

搜索这个报错,是kafka broker侧有个配置message.max.bytes,默认为1MB,如果发送的消息体积大于这个,就会报错。
《kafka权威指南》说这个是限制单条record消息体积大小的。

image.png

官方文档 也是这么说的

image.png

The request included a message larger than the max message size the server will accept.

这些都指向request里面某个record超过了kafka broker侧message.max.bytes配置。

当服务端返回MESSAGE_TOO_LARGE报错后,客户端将消息拆分成更小的批次进行重新发送,所以会凭空产生很多消息的错觉。没去探究拆分逻辑,是怎么从1000r/s拆到15000r/s的也是奇怪,最好合理设置参数避免这种场景。

image.png

确定kafka broker侧message.max.bytes配置大小

开始我想通过kafka自带的kafka-config.sh,却发现在我这个版本,这个脚本带的命令不会反馈所有配置,只会返回你动态修改过的那些。
kafka-manager界面点击topic的配置,也只会显示空

通过搜索上面这个问题,我发现了 Getting broker configuration via kafka-configs.sh

Yes this is a known behavior: https://issues.apache.org/jira/browse/KAFKA-7720

Currently this tool only shows configurations that have been dynamically overridden.

To see all broker configs, you have 2 options:

Use the AdminClient.describeConfigs() API
Tweak the ConfigCommand.scala tool. Just remove the filter on https://github.com/apache/kafka/blob/ad26914de65e2db244fbe36a2a5fd03de87dfb79/core/src/main/scala/kafka/admin/ConfigCommand.scala#L347
Update: This issue is being addressed by KIP-524 which is currently targetted for Kafka 2.5

后面我到server.log去grep

我在server.log里发现了这个配置的大小kafka实际生效的message.max.bytes值是1000012字节,0.95左右,小于1MB。

bash-4.4# cat server.log.*|grep message.max.bytes
        message.max.bytes = 1000012
        message.max.bytes = 1000012
        message.max.bytes = 1000012
        message.max.bytes = 1000012
        message.max.bytes = 1000012
        message.max.bytes = 1000012

topic层的配置没有进行覆盖,所以参数值确定为1000012字节

疑问

但实际上我这次压测采用的消息体积是固定的,kafka producer metrics的record-size-avg是2.7KB,record-size-max是9.6KB,远远小于1000012字节。
为什么这样还会被拒绝呢。

调整batch.size重新测试

我将batch.size调整到512KB, max.request.size调整到2MB,重新压测,这次日志里不再刷MESSAGE_TOO_LARGE报错了。
record-send-rate恢复到1000r/s每秒,record-error-rate为0.问题消除
这里我已经感觉message.max.bytes可能限制的不是单条消息的大小,而是限制的batch.size的大小。

去kafka源码探究message.max.bytes

https://github.com/apache/kafka/blob/847ff8f/core/src/main/scala/kafka/log/Log.scala#L1377

  // Check if the message sizes are valid.
  val batchSize = batch.sizeInBytes
  if (batchSize > config.maxMessageSize) {
    brokerTopicStats.topicStats(topicPartition.topic).bytesRejectedRate.mark(records.sizeInBytes)
    brokerTopicStats.allTopicsStats.bytesRejectedRate.mark(records.sizeInBytes)
    throw new RecordTooLargeException(s"The record batch size in the append to $topicPartition is $batchSize bytes " +
      s"which exceeds the maximum configured value of ${config.maxMessageSize}.")
  }

image.png

不知道我这段看的对不对,不过确实非常可能是message.max.bytes是限制的batch.size的大小。

总结

batch.size最好比服务端实际生效的message.max.bytes配置小一些,否则在笔者所在的版本会遇到MESSAGE_TOO_LARGE报错,客户端进行重试发送造成很大的消息发送量。这个重试是可以避免发生的。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 213,558评论 6 492
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,002评论 3 387
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 159,036评论 0 349
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,024评论 1 285
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,144评论 6 385
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,255评论 1 292
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,295评论 3 412
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,068评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,478评论 1 305
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,789评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,965评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,649评论 4 336
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,267评论 3 318
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,982评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,223评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,800评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,847评论 2 351