kafka实战-消费者offset重置问题

kafka实战-消费者offset重置问题

背景

背景：当app启动时，会调用 “启动上报接口” 上报启动数据，该数据包含且不限于手机型号、应用版本、app类型、启动时间等，一站式接入平台系统会记录该数据。

生产者：“启动上报接口”会根据启动数据发送一条kafka消息，topic“xxx”

消费者：“启动处理模块”会监控topic “xxx”，当发现消息时进行消费，将启动数据存放至相应的数据库中。

问题现象

当生产者和消费者的项目都启动后，我们发现，生产者在不断的生产消息，消费者在不断的进行消费，查询数据库中的启动数据也确实增加了，但是当前 consumer 的 offset 却一直是0。

监控了十分钟，发现如下现象：数据库数据确实增加，但是相同的数据却重复出现了N次，N随时间增加。

查看日志发现如下现象：

2023-02-0123:13:55,323[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.apache.kafka.clients.consumer.internals.ConsumerCoordinator[273]-[Consumer clientId=start-consumer-35, groupId=app-loginfo-message-consumer] Adding newly assigned partitions:CONSUMER-72023-02-0123:13:55,434[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.apache.kafka.clients.consumer.internals.ConsumerCoordinator[1306]-[Consumer clientId=start-consumer-35, groupId=app-loginfo-message-consumer] Found no committed offset for partition CONSUMER-72023-02-0123:13:55,716[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.apache.kafka.clients.consumer.internals.SubscriptionState[397]-[Consumer clientId=start-consumer-35, groupId=app-loginfo-message-consumer] Resetting offset for partition CONSUMER-7 to offset 0.2023-02-0123:13:55,717[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.springframework.kafka.listener.KafkaMessageListenerContainer[292]- app-loginfo-message-consumer: partitions assigned:[CONSUMER-7]...2023-02-0123:19:23,425[...KafkaListenerEndpointContainer#5-7-C-1]INFO com...service.impl.StartServiceImpl[200]-[TID:4cf33af14b3a4b8cb76f4179594f38f2_201_16752639927830001]--- enterStartupLog success:业务日志
2023-02-0123:19:23,425[...KafkaListenerEndpointContainer#5-7-C-1]INFO com...listener.ApiKafkaListener[58]-[TID:4cf33af14b3a4b8cb76f4179594f38f2_201_16752639927830001]--- tag:UPMAPI_APP_START_REPORT,message:业务日志
2023-02-0123:19:23,425[...KafkaListenerEndpointContainer#5-7-C-1]INFO com...service.impl.StatisticsServiceImpl[142]-[TID:4cf33af14b3a4b8cb76f4179594f38f2_201_16752639927830001]--- 业务日志
2023-02-0123:19:23,811[...KafkaListenerEndpointContainer#5-7-C-1]INFO com...service.impl.StartServiceImpl[200]-[TID:4cf33af14b3a4b8cb76f4179594f38f2_201_16752639927830001]--- enterStartupLog success:业务日志
2023-02-0123:19:23,811[...KafkaListenerEndpointContainer#5-7-C-1]INFO com...listener.ApiKafkaListener[58]-[TID:4cf33af14b3a4b8cb76f4179594f38f2_201_16752639927830001]--- tag:UPMAPI_APP_START_REPORT,message:业务日志
2023-02-0123:19:23,812[...KafkaListenerEndpointContainer#5-7-C-1]INFO com...service.impl.StatisticsServiceImpl[142]-[TID:4cf33af14b3a4b8cb76f4179594f38f2_201_16752639927830001]--- 业务日志
2023-02-0123:19:24,108[...KafkaListenerEndpointContainer#5-7-C-1]INFO com...service.impl.StartServiceImpl[200]-[TID:4cf33af14b3a4b8cb76f4179594f38f2_201_16752639927830001]--- enterStartupLog success:业务日志
2023-02-0123:19:24,108[...KafkaListenerEndpointContainer#5-7-C-1]INFO org...apache.kafka.clients.consumer.internals.ConsumerCoordinator[1107]-[Consumer clientId=start-consumer-35, groupId=app-loginfo-message-consumer] Failing OffsetCommit request since the consumer is not part of an active group
2023-02-0123:19:24,109[...KafkaListenerEndpointContainer#5-7-C-1]ERROR org.apache.kafka.clients.consumer.internals.AbstractCoordinator[1013]-[Consumer clientId=start-consumer-35, groupId=app-loginfo-message-consumer] LeaveGroup request failed witherror: The coordinator is not aware ofthis member.2023-02-0123:19:24,109[...KafkaListenerEndpointContainer#5-7-C-1]ERROR org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer[149]- Consumer exception java.lang.IllegalStateException: This error handler cannot process 'org.apache.kafka.clients.consumer.CommitFailedException's; no record information is available at org.springframework.kafka.listener.SeekUtils.seekOrRecover(SeekUtils.java:151) at org.springframework.kafka.listener.SeekToCurrentErrorHandler.handle(SeekToCurrentErrorHandler.java:113) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.handleConsumerException(KafkaMessageListenerContainer.java:1361) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.run(KafkaMessageListenerContainer.java:1063) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.lang.Thread.run(Thread.java:748) Caused by: org.apache.kafka.clients.consumer.CommitFailedException: Offset commit cannot be completed since the consumer is not part of an active group for auto partition assignment; it is likely that the consumer was kicked out of the group. at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.sendOffsetCommitRequest(ConsumerCoordinator.java:1116) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.commitOffsetsSync(ConsumerCoordinator.java:983) at org.apache.kafka.clients.consumer.KafkaConsumer.commitSync(KafkaConsumer.java:1510) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.doCommitSync(KafkaMessageListenerContainer.java:2311) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.commitSync(KafkaMessageListenerContainer.java:2306) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.commitIfNecessary(KafkaMessageListenerContainer.java:2292) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.processCommits(KafkaMessageListenerContainer.java:2106) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.pollAndInvoke$original$cUFzUMfk(KafkaMessageListenerContainer.java:1097) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.pollAndInvoke$original$cUFzUMfk$accessor$KCXsM7NI(KafkaMessageListenerContainer.java) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer$auxiliary$YPllDASy.call(Unknown Source) at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:86) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.pollAndInvoke(KafkaMessageListenerContainer.java) at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.run(KafkaMessageListenerContainer.java:1031)...3 common frames omitted
2023-02-0123:19:24,109[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.apache.kafka.clients.consumer.internals.ConsumerCoordinator[676]-[Consumer clientId=start-consumer-35, groupId=app-loginfo-message-consumer] Giving away all assigned partitions as lost since generation has been reset,indicating that consumer is no longer part of the group
2023-02-0123:19:24,109[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.apache.kafka.clients.consumer.internals.ConsumerCoordinator[311]-[Consumer clientId=consumer-app-loginfo-message-consumer-35, groupId=app-loginfo-message-consumer] Lost previously assigned partitions CONSUMER-72023-02-0123:19:24,109[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.springframework.kafka.listener.KafkaMessageListenerContainer[292]- app-loginfo-message-consumer: partitions lost:[CONSUMER-7]2023-02-0123:19:24,109[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.springframework.kafka.listener.KafkaMessageListenerContainer[292]- app-loginfo-message-consumer: partitions revoked:[CONSUMER-7]2023-02-0123:19:24,110[...KafkaListenerEndpointContainer#5-7-C-1]INFO org.apache.kafka.clients.consumer.internals.AbstractCoordinator[552]-[Consumer clientId=start-consumer-35, groupId=app-loginfo-message-consumer](Re-)joining group

23:13:55发现消息并将offset置为0，然后开始poll，进行消费。

处理到23:19:24时全部数据处理完毕，开始提交offset。此时报错提交失败，消费者已离开消费组，当前消费者已分配的分区丢失。

然后当前消费者重新加入消费者，offset重置为0，从头开始消费。

分析原因

从以上日志可以看出，消费者正确消费，不存在报错的现象，kafka offset手动提交代码无误。因此可以断定报错原因不是业务异常，而是由于kafka自身机制导致的提交失败。

查看发现当前消费者制配置如下：

allow.auto.create.topics = true
auto.commit.interval.ms = 1000
auto.offset.reset = earliest
bootstrap.servers = [ip0:9092, ip1:9092, ip2:9092]
check.crcs = true
client.dns.lookup = default
client.id = 
client.rack = 
connections.max.idle.ms = 540000
default.api.timeout.ms = 60000
enable.auto.commit = false
exclude.internal.topics = true
fetch.max.bytes = 52428800
fetch.max.wait.ms = 500
fetch.min.bytes = 1
group.id = app-loginfo-message-consumer
group.instance.id = null
heartbeat.interval.ms = 3000
interceptor.classes = []
internal.leave.group.on.close = true
isolation.level = read_uncommitted
key.deserializer = class org.apache.kafka.common.serialization.StringDeserializer
max.partition.fetch.bytes = 1048576
max.poll.interval.ms = 300000
max.poll.records = 500
metadata.max.age.ms = 300000
metric.reporters = []
metrics.num.samples = 2
metrics.recording.level = INFO
metrics.sample.window.ms = 30000
partition.assignment.strategy = [class org.apache.kafka.clients.consumer.RangeAssignor]
receive.buffer.bytes = 65536
reconnect.backoff.max.ms = 1000
reconnect.backoff.ms = 50
request.timeout.ms = 30000
retry.backoff.ms = 100
sasl.client.callback.handler.class = null
sasl.jaas.config = null
sasl.kerberos.kinit.cmd = /usr/bin/kinit
sasl.kerberos.min.time.before.relogin = 60000
sasl.kerberos.service.name = null
sasl.kerberos.ticket.renew.jitter = 0.05
sasl.kerberos.ticket.renew.window.factor = 0.8
sasl.login.callback.handler.class = null
sasl.login.class = null
sasl.login.refresh.buffer.seconds = 300
sasl.login.refresh.min.period.seconds = 60
sasl.login.refresh.window.factor = 0.8
sasl.login.refresh.window.jitter = 0.05
sasl.mechanism = GSSAPI
security.protocol = PLAINTEXT
security.providers = null
send.buffer.bytes = 131072
session.timeout.ms = 30000
ssl.cipher.suites = null
ssl.enabled.protocols = [TLSv1.2]
ssl.endpoint.identification.algorithm = https
ssl.key.password = null
ssl.keymanager.algorithm = SunX509
ssl.keystore.location = null
ssl.keystore.password = null
ssl.keystore.type = JKS
ssl.protocol = TLSv1.2
ssl.provider = null
ssl.secure.random.implementation = null
ssl.trustmanager.algorithm = PKIX
ssl.truststore.location = null
ssl.truststore.password = null
ssl.truststore.type = JKS
value.deserializer = class org.apache.kafka.common.serialization.StringDeserializer

通过查看配置发现，由于启动数据量大，消费者每次拉取的消息数量满载，达到max.poll.records = 500，即每次拉取500条消息进行消费，全部消费完毕后进行offset提交。

然而通过上述日志可以发现，一条消息消费的时间接近一秒，500条数据消费的总时间≈500*1s=500s，该时间远大于max.poll.interval.ms=300000设置的最大拉取时间（300s）。

因此，当达到最大时间300s时，kafka client发现当前消费者仍未进行过拉取，因此认为当前消费者处于非健康状态，将其从消费者组中剔除。

所以，当消费者消费500条消息完毕后进行提交时，发现自己不在消费者组中，故而提交offset失败。
提交失败后，当前消费者重新加入消费者组，offset又从起点开始拉取。

上述过程反复进行，导致offset不断被重置。

问题解决

通过问题分析我们得到，当前现象产生的关键点是：“指定时间不足以消费指定数量消息” 的问题。所以可得两种解决方式进行解决：一种是减小max.poll.records，使得指定时间内能够完成全部消费；另一种是增大max.poll.interval.ms，使得当前数量的消息全部消费完毕后，还未达到时间阈值。

由于以下两点原因，我们决定通过第一种方式，即减小max.poll.records的方式来解决该问题：

1.由于在生产环境，我们的消费者服务是docker部署，支持动态扩容的，且配置了concurrency=#{partitionCount}进行多线程消费，所以处理速度完全满足业务需求，不会造成消息堆积。

2.max.poll.interval.ms相当于消费者的探活时间，默认=300000即3分钟，如果设置过大则失去原有意义，所以一般情况下，在业务能力可以得到满足时，不建议修改该配置。

结果：设置max.poll.records=100，问题解决。

附-常见的消费者配置描述和调优方案

1. max.poll.records

作用：意味消费者一次poll()操作，能够获取的最大数据量。

注意：调整这个值能提升吞吐量，于此同时也需要同步提升max.poll.interval.ms的参数大小。设置之前，应该考虑并计算所有数据处理完毕的时间，务必要小于max.poll.interval.ms的参数大小。

2. fetch.max.bytes

作用：意味server端可返回给consumer的最大数据大小

注意：增加可以提升吞吐量，但是在客户端和服务端网络延迟比较大的环境下，建议可以减小该值，防止业务处理数据超时。

3. heartbeat.interval.ms

作用：消费超时时间,consumer与kafka之间的超时时间

注意：该参数不能超过session.timeout.ms，通常设置为session.timeout.ms的三分之一,默认值:3000。

4. max.partition.fetch.bytes

作用：限制每个consumer发起fetch请求时候，读到数据（record）的限制

注意：设置过大，consumer本地缓存的数据就会越多，可能影响内存的使用,默认值：1048576。

5. fetch.max.bytes

作用：server端可返回给consumer的最大数据大小

注意：数值可大于max.partition.fetch.bytes，一般设置为默认值即可，默认值：52428800

6. session.timeout.ms

作用：使用consumer组管理offset时，consumer与broker之间的心跳超时时间

注意：如果consumer消费数据的频率非常低，建议增大这个参数值，默认值：10000。

7. auto.offset.reset

作用：消费过程中无法找到数据消费到的offset位置，所选择的消费策略

注意：earliest：从头开始消费，可能会消费到重复数据，latest：从数据末尾开始消费，可能会丢失数据。默认值：earlist。

8. max.poll.interval.ms

作用：消费者在每一轮poll() (拉取数据之间的最大时间延迟)，默认值：300s

注意：如果此超时时间期满之前poll()没有被再次调用，则消费者被视为失败，并且分组将触发rebalance，以便将分区重新分配给别的成员

如果，再两次poll之间需要添加过多复杂的，耗时的逻辑，需要延长这个时间；当然，如果当前消费的消息消费结果可以忽略，即失败也无所谓，比如某些统计次数的场景等，数量有少数差异不影响业务使用，那么可以设置为异步处理，此时就不会消耗大量时间。

9. max.poll.records

作用：消费者一次poll（）操作，能够获取的最大数据量

注意：增加这个参数值，会增加一次性拉取数据的数据量，确保拉取数据的时间，至少在max.poll.interval.ms规定的范围之内，默认值：500

完

更多优化内容可查看 5种kafka消费端性能优化方法