search

childe / healer

golang lib for kafka
22 stars 18 forks source link

按照example,操作报错 #25

Closed zhao519522607 closed 1 year ago

zhao519522607 commented 1 year ago

RROR: logging before flag.Parse: I0224 18:11:33.194686 42484 simple_consumer.go:180] consume [wormhole_center-info-log][0] from 77284905 ERROR: logging before flag.Parse: E0224 18:11:33.210818 42484 fetch_response.go:525] The leader epoch in the request is older than the epoch on the broker ERROR: logging before flag.Parse: E0224 18:11:33.210818 42484 simple_consumer.go:448] consumer wormhole_center-info-log[0] error:The leader epoch in the request is older than the epoch on the broker ERROR: logging before flag.Parse: E0224 18:11:33.317739 42484 fetch_response.go:525] The leader epoch in the request is older than the epoch on the broker ERROR: logging before flag.Parse: E0224 18:11:33.317739 42484 simple_consumer.go:448] consumer wormhole_center-info-log[0] error:The leader epoch in the request is older than the epoch on the broker ERROR: logging before flag.Parse: E0224 18:11:33.377426 42484 fetch_response.go:525] The leader epoch in the request is older than the epoch on the broker ERROR: logging before flag.Parse: E0224 18:11:33.377426 42484 simple_consumer.go:448] consumer wormhole_center-info-log[0] error:The leader epoch in the request is older than the epoch on the broker ERROR: logging before flag.Parse: E0224 18:11:33.394868 42484 fetch_response.go:525] The leader epoch in the request is older than the epoch on the broker

childe commented 1 year ago

抱歉，我以为手机已经回复了。

这个应该是因为你使用的 healer 版本比较低？ 这个报错在 13e2a18 附近几个 Commit 处理过。

zhao519522607 commented 1 year ago

我用的v0.3.2

1677463408189

childe commented 1 year ago

我拿 example 里面的代码去消费数据， 没问题。 看下

  1. 你的 kafka 版本？
  2. 你的代码。
zhao519522607 commented 1 year ago

image kafka_2.12-2.8.0

childe commented 1 year ago

抱歉，漏了两点。

  1. 代码最开始，需要 flag.Parse() 一下。
  2. 运行的时候，加参数 -v 10 --logtostderr ，然后把日志发来看一下吧。
zhao519522607 commented 1 year ago

image 抱歉，我这里访问git有时候打开有问题，回复比较慢

zhao519522607 commented 1 year ago

image

zhao519522607 commented 1 year ago

image

zhao519522607 commented 1 year ago

I0227 11:11:30.372114 34960 broker.go:247] 192.168.2.71:63842 -> 172.26.108.216:9092 I0227 11:11:30.384953 34960 broker.go:251] request length: 25. api: ApiVersions(0). CorrelationID: 1. timeout: 30000 I0227 11:11:30.553171 34960 broker.go:282] response length in header: 350 I0227 11:11:30.553171 34960 broker.go:306] response length: 350. CorrelationID: 1 I0227 11:11:30.567154 34960 broker.go:83] broker 172.26.108.216:9092 api versions: Produce:0-9,Fetch:0-12,ListOffsets:0-6,Metadata:0-11,LeaderAndIsr:0-5,StopReplica:0-3,UpdateMetadata:0-7,ControlledShutdown:0-3,OffsetCommit:0-8,OffsetFetch:0-7,FindCoordinator:0-3,JoinGroup:0-7,Heartbeat:0-4,LeaveGroup:0-4,SyncGroup:0-5,DescribeGroups:0-5,ListGroups:0-4,SaslHandshake:0-1,ApiVersions:0-3,CreateTopics:0-7,DeleteTopics:0-6,DeleteRecords:0-2,InitProducerId:0-4,OffsetForLeaderEpoch:0-4,AddPartitionsToTxn:0-3,AddOffsetsToTxn:0-3,EndTxn:0-3,WriteTxnMarkers:0-1,TxnOffsetCommit:0-3,DescribeAcls:0-2,CreateAcls:0-2,DeleteAcls:0-2,DescribeConfigs:0-4,AlterConfigs:0-2,AlterReplicaLogDirs:0-2,DescribeLogDirs:0-2,SaslAuthenticate:0-2,CreatePartitions:0-3,CreateDelegationToken:0-2,RenewDelegationToken:0-2,ExpireDelegationToken:0-2,DescribeDelegationToken:0-2,DeleteGroups:0-2,ElectLeaders:0-2,IncrementalAlterConfigs:0-1,AlterPartitionReassignments:0-0,ListPartitionReassignments:0-0,OffsetDelete:0-0,DescribeClientQuotas:0-1,AlterClientQuotas:0-1,DescribeUserScramCredentials:0-0,AlterUserScramCredentials:0-0,AlterIsr:0-0,UpdateFeatures:0-0,DescribeCluster:0-0,DescribeProducers:0-0 I0227 11:11:30.567279 34960 broker.go:247] 192.168.2.71:63842 -> 172.26.108.216:9092 I0227 11:11:30.567279 34960 broker.go:251] request length: 36. api: Metadata(7). CorrelationID: 2. timeout: 30000 I0227 11:11:30.583443 34960 broker.go:282] response length in header: 126 I0227 11:11:30.583443 34960 broker.go:306] response length: 126. CorrelationID: 2 I0227 11:11:30.583443 34960 brokers.go:94] got 3 brokers I0227 11:11:30.583443 34960 brokers.go:97] 218 172.26.108.218:9092 I0227 11:11:30.583443 34960 brokers.go:97] 216 172.26.108.216:9092 I0227 11:11:30.583443 34960 brokers.go:97] 217 172.26.108.217:9092 I0227 11:11:30.621337 34960 broker.go:247] 192.168.2.71:63843 -> 172.26.108.217:9092 I0227 11:11:30.621337 34960 broker.go:251] request length: 25. api: ApiVersions(0). CorrelationID: 1. timeout: 30000 I0227 11:11:30.783761 34960 broker.go:282] response length in header: 350 I0227 11:11:30.783761 34960 broker.go:306] response length: 350. CorrelationID: 1 I0227 11:11:30.789368 34960 broker.go:83] broker 172.26.108.217:9092 api versions: Produce:0-9,Fetch:0-12,ListOffsets:0-6,Metadata:0-11,LeaderAndIsr:0-5,StopReplica:0-3,UpdateMetadata:0-7,ControlledShutdown:0-3,OffsetCommit:0-8,OffsetFetch:0-7,FindCoordinator:0-3,JoinGroup:0-7,Heartbeat:0-4,LeaveGroup:0-4,SyncGroup:0-5,DescribeGroups:0-5,ListGroups:0-4,SaslHandshake:0-1,ApiVersions:0-3,CreateTopics:0-7,DeleteTopics:0-6,DeleteRecords:0-2,InitProducerId:0-4,OffsetForLeaderEpoch:0-4,AddPartitionsToTxn:0-3,AddOffsetsToTxn:0-3,EndTxn:0-3,WriteTxnMarkers:0-1,TxnOffsetCommit:0-3,DescribeAcls:0-2,CreateAcls:0-2,DeleteAcls:0-2,DescribeConfigs:0-4,AlterConfigs:0-2,AlterReplicaLogDirs:0-2,DescribeLogDirs:0-2,SaslAuthenticate:0-2,CreatePartitions:0-3,CreateDelegationToken:0-2,RenewDelegationToken:0-2,ExpireDelegationToken:0-2,DescribeDelegationToken:0-2,DeleteGroups:0-2,ElectLeaders:0-2,IncrementalAlterConfigs:0-1,AlterPartitionReassignments:0-0,ListPartitionReassignments:0-0,OffsetDelete:0-0,DescribeClientQuotas:0-1,AlterClientQuotas:0-1,DescribeUserScramCredentials:0-0,AlterUserScramCredentials:0-0,AlterIsr:0-0,UpdateFeatures:0-0,DescribeCluster:0-0,DescribeProducers:0-0 I0227 11:11:30.789449 34960 broker.go:247] 192.168.2.71:63843 -> 172.26.108.217:9092 I0227 11:11:30.789515 34960 broker.go:251] request length: 30. api: FindCoordinator(0). CorrelationID: 2. timeout: 30000 I0227 11:11:30.805296 34960 broker.go:282] response length in header: 34 I0227 11:11:30.805296 34960 broker.go:306] response length: 34. CorrelationID: 2 I0227 11:11:30.808444 34960 group_consumer.go:141] coordinator for group[zyb_test]:172.26.108.217:9092 I0227 11:11:30.808444 34960 group_consumer.go:173] try to join group zyb_test I0227 11:11:30.808444 34960 broker.go:247] 192.168.2.71:63843 -> 172.26.108.217:9092 I0227 11:11:30.808444 34960 broker.go:251] request length: 101. api: JoinGroup(1). CorrelationID: 3. timeout: 35000 I0227 11:11:30.852260 34960 broker.go:282] response length in header: 200 I0227 11:11:30.852260 34960 broker.go:306] response length: 200. CorrelationID: 3 I0227 11:11:30.857003 34960 group_consumer.go:190] join response:{"CorrelationID":3,"ErrorCode":0,"GenerationID":5,"GroupProtocol":"range","LeaderID":"healer-74f5c8d0-2376-4965-9341-620435a9445c","MemberID":"healer-74f5c8d0-2376-4965-9341-620435a9445c","Members":[{"MemberID":"healer-74f5c8d0-2376-4965-9341-620435a9445c","MemberMetadata":"AAAAAAABABh3b3JtaG9sZV9jZW50ZXItaW5mby1sb2cAAAAA"}]} I0227 11:11:30.857003 34960 group_consumer.go:220] memberID now is healer-74f5c8d0-2376-4965-9341-620435a9445c I0227 11:11:30.857003 34960 group_consumer.go:232] try to sync group zyb_test I0227 11:11:30.879353 34960 broker.go:247] 192.168.2.71:63844 -> 172.26.108.218:9092 I0227 11:11:30.879396 34960 broker.go:251] request length: 25. api: ApiVersions(0). CorrelationID: 1. timeout: 30000 I0227 11:11:31.184115 34960 broker.go:282] response length in header: 350 I0227 11:11:31.184343 34960 broker.go:306] response length: 350. CorrelationID: 1 I0227 11:11:31.184343 34960 broker.go:83] broker 172.26.108.218:9092 api versions: Produce:0-9,Fetch:0-12,ListOffsets:0-6,Metadata:0-11,LeaderAndIsr:0-5,StopReplica:0-3,UpdateMetadata:0-7,ControlledShutdown:0-3,OffsetCommit:0-8,OffsetFetch:0-7,FindCoordinator:0-3,JoinGroup:0-7,Heartbeat:0-4,LeaveGroup:0-4,SyncGroup:0-5,DescribeGroups:0-5,ListGroups:0-4,SaslHandshake:0-1,ApiVersions:0-3,CreateTopics:0-7,DeleteTopics:0-6,DeleteRecords:0-2,InitProducerId:0-4,OffsetForLeaderEpoch:0-4,AddPartitionsToTxn:0-3,AddOffsetsToTxn:0-3,EndTxn:0-3,WriteTxnMarkers:0-1,TxnOffsetCommit:0-3,DescribeAcls:0-2,CreateAcls:0-2,DeleteAcls:0-2,DescribeConfigs:0-4,AlterConfigs:0-2,AlterReplicaLogDirs:0-2,DescribeLogDirs:0-2,SaslAuthenticate:0-2,CreatePartitions:0-3,CreateDelegationToken:0-2,RenewDelegationToken:0-2,ExpireDelegationToken:0-2,DescribeDelegationToken:0-2,DeleteGroups:0-2,ElectLeaders:0-2,IncrementalAlterConfigs:0-1,AlterPartitionReassignments:0-0,ListPartitionReassignments:0-0,OffsetDelete:0-0,DescribeClientQuotas:0-1,AlterClientQuotas:0-1,DescribeUserScramCredentials:0-0,AlterUserScramCredentials:0-0,AlterIsr:0-0,UpdateFeatures:0-0,DescribeCluster:0-0,DescribeProducers:0-0 I0227 11:11:31.184343 34960 broker.go:247] 192.168.2.71:63844 -> 172.26.108.218:9092 I0227 11:11:31.184343 34960 broker.go:251] request length: 51. api: Metadata(7). CorrelationID: 2. timeout: 30000 I0227 11:11:31.184847 34960 broker.go:282] response length in header: 193 I0227 11:11:31.184847 34960 broker.go:306] response length: 193. CorrelationID: 2 I0227 11:11:31.200083 34960 group_consumer.go:124] topics[[wormhole_center-info-log]] metadata :{"CorrelationID":2,"ThrottleTimeMs":0,"Brokers":[{"NodeID":218,"Host":"172.26.108.218","Port":9092,"Rack":""},{"NodeID":216,"Host":"172.26.108.216","Port":9092,"Rack":""},{"NodeID":217,"Host":"172.26.108.217","Port":9092,"Rack":""}],"ClusterID":"\u0000\u0016rmmr1wemSOy0CbaXgNLU","ControllerID":216,"TopicMetadatas":[{"TopicErrorCode":0,"TopicName":"wormhole_center-info-log","IsInternal":false,"PartitionMetadatas":[{"PartitionErrorCode":0,"PartitionID":0,"Leader":216,"LeaderEpoch":11,"Replicas":[216],"Isr":[216],"OfflineReplicas":[]}]}]} I0227 11:11:31.200083 34960 assign.go:113] topic partitions assignments:map[wormhole_center-info-log:map[healer-74f5c8d0-2376-4965-9341-620435a9445c:[0]]] I0227 11:11:31.200083 34960 assign.go:139] memberAssignments:map[healer-74f5c8d0-2376-4965-9341-620435a9445c:0xc0000ba240] I0227 11:11:31.200083 34960 group_consumer.go:240] group assignment: [{healer-74f5c8d0-2376-4965-9341-620435a9445c [0 0 0 0 0 1 0 24 119 111 114 109 104 111 108 101 95 99 101 110 116 101 114 45 105 110 102 111 45 108 111 103 0 0 0 1 0 0 0 0 0 0 0 0]}] I0227 11:11:31.200083 34960 broker.go:247] 192.168.2.71:63843 -> 172.26.108.217:9092 I0227 11:11:31.200083 34960 broker.go:251] request length: 176. api: SyncGroup(0). CorrelationID: 4. timeout: 30000 I0227 11:11:31.200588 34960 broker.go:282] response length in header: 58 I0227 11:11:31.200588 34960 broker.go:306] response length: 58. CorrelationID: 4 I0227 11:11:31.214444 34960 group_consumer.go:247] sync response:{"CorrelationID":4,"ErrorCode":0,"MemberAssignment":"AAAAAAABABh3b3JtaG9sZV9jZW50ZXItaW5mby1sb2cAAAABAAAAAAAAAAA="} I0227 11:11:31.214571 34960 group_consumer.go:154] memeber assignment:{"Version":0,"PartitionAssignments":[{"Topic":"wormhole_center-info-log","Partitions":[0]}],"UserData":""} I0227 11:11:31.214571 34960 broker.go:247] 192.168.2.71:63844 -> 172.26.108.218:9092 I0227 11:11:31.214571 34960 broker.go:251] request length: 30. api: FindCoordinator(0). CorrelationID: 3. timeout: 30000 I0227 11:11:31.214699 34960 broker.go:282] response length in header: 34 I0227 11:11:31.214699 34960 broker.go:306] response length: 34. CorrelationID: 3 I0227 11:11:31.230137 34960 simple_consumer.go:120] coordinator for group[zyb_test]:172.26.108.217:9092 I0227 11:11:31.230137 34960 simple_consumer.go:332] [wormhole_center-info-log][0] offset: -1 (before fetch offset) I0227 11:11:31.230137 34960 broker.go:247] 192.168.2.71:63844 -> 172.26.108.218:9092 I0227 11:11:31.230254 34960 broker.go:251] request length: 51. api: Metadata(7). CorrelationID: 4. timeout: 30000 I0227 11:11:31.268558 34960 broker.go:282] response length in header: 193 I0227 11:11:31.279119 34960 broker.go:306] response length: 193. CorrelationID: 4 I0227 11:11:31.279119 34960 simple_consumer.go:143] leader ID of [wormhole_center-info-log][0] is 216 I0227 11:11:31.332137 34960 broker.go:247] 192.168.2.71:63845 -> 172.26.108.216:9092 I0227 11:11:31.332137 34960 broker.go:251] request length: 25. api: ApiVersions(0). CorrelationID: 1. timeout: 30000 I0227 11:11:31.484373 34960 broker.go:282] response length in header: 350 I0227 11:11:31.485730 34960 broker.go:306] response length: 350. CorrelationID: 1 I0227 11:11:31.485767 34960 broker.go:83] broker 172.26.108.216:9092 api versions: Produce:0-9,Fetch:0-12,ListOffsets:0-6,Metadata:0-11,LeaderAndIsr:0-5,StopReplica:0-3,UpdateMetadata:0-7,ControlledShutdown:0-3,OffsetCommit:0-8,OffsetFetch:0-7,FindCoordinator:0-3,JoinGroup:0-7,Heartbeat:0-4,LeaveGroup:0-4,SyncGroup:0-5,DescribeGroups:0-5,ListGroups:0-4,SaslHandshake:0-1,ApiVersions:0-3,CreateTopics:0-7,DeleteTopics:0-6,DeleteRecords:0-2,InitProducerId:0-4,OffsetForLeaderEpoch:0-4,AddPartitionsToTxn:0-3,AddOffsetsToTxn:0-3,EndTxn:0-3,WriteTxnMarkers:0-1,TxnOffsetCommit:0-3,DescribeAcls:0-2,CreateAcls:0-2,DeleteAcls:0-2,DescribeConfigs:0-4,AlterConfigs:0-2,AlterReplicaLogDirs:0-2,DescribeLogDirs:0-2,SaslAuthenticate:0-2,CreatePartitions:0-3,CreateDelegationToken:0-2,RenewDelegationToken:0-2,ExpireDelegationToken:0-2,DescribeDelegationToken:0-2,DeleteGroups:0-2,ElectLeaders:0-2,IncrementalAlterConfigs:0-1,AlterPartitionReassignments:0-0,ListPartitionReassignments:0-0,OffsetDelete:0-0,DescribeClientQuotas:0-1,AlterClientQuotas:0-1,DescribeUserScramCredentials:0-0,AlterUserScramCredentials:0-0,AlterIsr:0-0,UpdateFeatures:0-0,DescribeCluster:0-0,DescribeProducers:0-0 I0227 11:11:31.485767 34960 simple_consumer.go:156] got leader broker 172.26.108.216:9092 with id 216 I0227 11:11:31.485767 34960 broker.go:247] 192.168.2.71:63843 -> 172.26.108.217:9092 I0227 11:11:31.485767 34960 broker.go:251] request length: 68. api: OffsetFetch(1). CorrelationID: 5. timeout: 30000 I0227 11:11:31.501923 34960 broker.go:282] response length in header: 58 I0227 11:11:31.501923 34960 broker.go:306] response length: 58. CorrelationID: 5 I0227 11:11:31.501923 34960 simple_consumer.go:162] [wormhole_center-info-log][0] offset: 77427742 I0227 11:11:31.513365 34960 fetch_request.go:54] fetch request wormhole_center-info-log[0]:77427742, maxBytes:10485760 I0227 11:11:31.513365 34960 broker.go:314] request length: 111. api: 1 CorrelationID: 2 I0227 11:11:31.553213 34960 fetch_response.go:485] decode fetch correlationID: 2 E0227 11:11:31.553213 34960 fetch_response.go:525] The leader epoch in the request is older than the epoch on the broker I0227 11:11:31.553284 34960 fetch_response.go:534] fetch correlationID: 2 done E0227 11:11:31.553284 34960 simple_consumer.go:448] consumer wormhole_center-info-log[0] error:The leader epoch in the request is older than the epoch on the broker I0227 11:11:31.553350 34960 fetch_request.go:54] fetch request wormhole_center-info-log[0]:77427742, maxBytes:10485760 I0227 11:11:31.553350 34960 broker.go:314] request length: 111. api: 1 CorrelationID: 3 I0227 11:11:31.584762 34960 fetch_response.go:485] decode fetch correlationID: 3 E0227 11:11:31.586879 34960 fetch_response.go:525] The leader epoch in the request is older than the epoch on the broker I0227 11:11:31.586879 34960 fetch_response.go:534] fetch correlationID: 3 done E0227 11:11:31.586879 34960 simple_consumer.go:448] consumer wormhole_center-info-log[0] error:The leader epoch in the request is older than the epoch on the broker I0227 11:11:31.586879 34960 fetch_request.go:54] fetch request wormhole_center-info-log[0]:77427742, maxBytes:10485760 I0227 11:11:31.586879 34960 broker.go:314] request length: 111. api: 1 CorrelationID: 4 I0227 11:11:31.684402 34960 fetch_response.go:485] decode fetch correlationID: 4 E0227 11:11:31.698851 34960 fetch_response.go:525] The leader epoch in the request is older than the epoch on the broker I0227 11:11:31.698851 34960 fetch_response.go:534] fetch correlationID: 4 done

childe commented 1 year ago

怀疑是代码里面还有一个 Bug，导致 meta 信息没有及时刷新。 目前是写死的，一分钟刷新一次。

你能不能等一分钟之后，看看是不是可以消费了？

我这边也改下代码，发一个 v.0.3.3 （但目前我也不敢保证是这个导致的，也期望你能帮忙测下看）

childe commented 1 year ago

怀疑是代码里面还有一个 Bug，导致 meta 信息没有及时刷新。 目前是写死的，一分钟刷新一次。

你能不能等一分钟之后，看看是不是可以消费了？

我这边也改下代码，发一个 v.0.3.3 （但目前我也不敢保证是这个导致的，也期望你能帮忙测下看）

v0.3.3 也发了

zhao519522607 commented 1 year ago

好的，我测试一下，感谢支持

zhao519522607 commented 1 year ago

我刚尝试了升级到v0.3.3版本,并且自己的代码里面加了 image 依然存在报错

zhao519522607 commented 1 year ago

gohangout依赖这个库，我自己的编译的就是跑不通

childe commented 1 year ago

我现在看不出来有啥问题了 :(

最直接的 debug 手段就是改一下 healer 代码，打印更多日志，我在代码里没有打印这些日志。 你可以自己改一下 debug。

go mod vender， 然后修改 vendor 下面的代码，看一下

修改下面几个点

https://github.com/childe/healer/blob/a78307e852e4bddfd9ad822d42c4c8ad065ab533/simple_consumer.go#L106

https://github.com/childe/healer/blob/a78307e852e4bddfd9ad822d42c4c8ad065ab533/simple_consumer.go#L413

打印一下 partition。

就是看一下从 metadata 请求拿到的 leaderEpoch 是不是正确拿到了，值是多少。

我这边测下来，感觉是不是 kafka 本身有问题了，元数据在集群内部混乱了（遇到过类似情况）。你可以拿kafka 自己的消费脚本去消费一下看，是不是能正常消费。

childe commented 1 year ago

@zhao519522607 怎么样？用 kafka 自己的脚本能消费吗？ kafka server 上面应该有消费脚本。

aipan commented 1 year ago

我也遇到这个问题了，gohangout用v0.1.10这个可以，升级后就有问题

childe commented 1 year ago

v0.3.4 修复