2020-10-28 12:22:37.682 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/config/topics/__consumer_offsets serverPath:/config/topics/__consumer_offsets finished:false header:: 102,1 replyHeader:: 102,54,0 request:: '/config/topics/__consumer_offsets,#7b2276657273696f6e223a312c22636f6e666967223a7b22636f6d7072657373696f6e2e74797065223a2270726f6475636572222c22636c65616e75702e706f6c696379223a22636f6d70616374222c227365676d656e742e6279746573223a22313034383537363030227d7d,v{s{31,s{'world,'anyone}}},0 response:: '/config/topics/__consumer_offsets
2020-10-28 12:22:37.683 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.683 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.683 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.683 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.683 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.683 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:create cxid:0x67 zxid:0x37 txntype:1 reqpath:n/a
2020-10-28 12:22:37.683 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:create cxid:0x67 zxid:0x37 txntype:1 reqpath:n/a
2020-10-28 12:22:37.683 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got notification sessionid:0x1001183e8060000
2020-10-28 12:22:37.684 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/brokers/topics for sessionid 0x1001183e8060000
2020-10-28 12:22:37.684 DEBUG 27226 --- [ker-EventThread] kafka.zookeeper.ZooKeeperClient : [ZooKeeperClient Kafka server] Received event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/brokers/topics
2020-10-28 12:22:37.684 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/brokers/topics/__consumer_offsets serverPath:/brokers/topics/__consumer_offsets finished:false header:: 103,1 replyHeader:: 103,55,0 request:: '/brokers/topics/__consumer_offsets,#7b2276657273696f6e223a322c22706172746974696f6e73223a7b2232223a5b305d2c2231223a5b305d2c2234223a5b305d2c2230223a5b305d2c2233223a5b305d7d2c22616464696e675f7265706c69636173223a7b7d2c2272656d6f76696e675f7265706c69636173223a7b7d7d,v{s{31,s{'world,'anyone}}},0 response:: '/brokers/topics/__consumer_offsets
2020-10-28 12:22:37.684 DEBUG 27226 --- [ Test worker] tractDirtiesContextTestExecutionListener : Before test method: context [DefaultTestContext@4c86d4c testClass = StreamsConfigurationTest, testInstance = com.github.ajablonski.StreamsConfigurationTest@32ff0049, testMethod = shouldTransitionToRunningStateBeforeTimeout@StreamsConfigurationTest, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@6f619745 testClass = StreamsConfigurationTest, locations = '{}', classes = '{class com.github.ajablonski.StreamsConfiguration, class com.github.ajablonski.StreamsConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{spring.application.name=demo-application, spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}, org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true}', contextCustomizers = set[org.springframework.kafka.test.context.EmbeddedKafkaContextCustomizer@286523bc, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@53950fea, [ImportsContextCustomizer@7e41aeb8 key = [@org.apiguardian.api.API(consumers={"*"}, since="5.0", status=STABLE), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.kafka.test.condition.EmbeddedKafkaCondition.class}), @org.springframework.boot.autoconfigure.EnableAutoConfiguration(exclude={}, excludeName={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationPackages$Registrar.class}), @org.springframework.test.context.BootstrapWith(value=org.springframework.boot.test.context.SpringBootTestContextBootstrapper.class), @org.springframework.kafka.test.context.EmbeddedKafka(partitions=2, bootstrapServersProperty="", brokerPropertiesLocation="", zookeeperPort=0, topics={"WordCounts", "WordsForNumbers", "OutputTopic"}, controlledShutdown=false, count=1, brokerProperties={}, zkConnectionTimeout=6000, ports={0}, value=1, zkSessionTimeout=6000), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.test.context.junit.jupiter.SpringExtension.class}), @org.springframework.boot.test.context.SpringBootTest(args={}, webEnvironment=MOCK, value={}, properties={"spring.application.name=demo-application", "spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}"}, classes={com.github.ajablonski.StreamsConfiguration.class}), @org.springframework.boot.autoconfigure.AutoConfigurationPackage(basePackages={}, basePackageClasses={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationImportSelector.class})]], org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@412b5795, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@52281bb6, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.web.client.TestRestTemplateContextCustomizer@7b0749e2, org.springframework.boot.test.context.SpringBootTestArgs@1], contextLoader = 'org.springframework.boot.test.context.SpringBootContextLoader', parent = [null]], attributes = map[[empty]]], class annotated with @DirtiesContext [false] with mode [null], method annotated with @DirtiesContext [false] with mode [null].
2020-10-28 12:22:37.685 DEBUG 27226 --- [quest-handler-3] kafka.zk.AdminZkClient : Updated path /brokers/topics/__consumer_offsets with Map(__consumer_offsets-4 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-3 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-2 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-0 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-1 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=)) for replica assignment
2020-10-28 12:22:37.685 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.685 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getChildren2 cxid:0x68 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics
2020-10-28 12:22:37.685 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getChildren2 cxid:0x68 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics
2020-10-28 12:22:37.685 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.685 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.685 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.685 INFO 27226 --- [quest-handler-3] kafka.server.KafkaApis : [KafkaApi-0] Auto creation of topic __consumer_offsets with 5 partitions and replication factor 1 is successful
2020-10-28 12:22:37.685 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/brokers/topics serverPath:/brokers/topics finished:false header:: 104,12 replyHeader:: 104,55,0 request:: '/brokers/topics,T response:: v{'WordCounts,'WordsForNumbers,'OutputTopic,'__consumer_offsets},s{6,6,1603905755456,1603905755456,0,4,0,0,0,4,55}
2020-10-28 12:22:37.686 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.686 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getData cxid:0x69 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/__consumer_offsets
2020-10-28 12:22:37.686 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getData cxid:0x69 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/__consumer_offsets
2020-10-28 12:22:37.686 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.686 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.686 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.687 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/brokers/topics/__consumer_offsets serverPath:/brokers/topics/__consumer_offsets finished:false header:: 105,4 replyHeader:: 105,55,0 request:: '/brokers/topics/__consumer_offsets,T response:: #7b2276657273696f6e223a322c22706172746974696f6e73223a7b2232223a5b305d2c2231223a5b305d2c2234223a5b305d2c2230223a5b305d2c2233223a5b305d7d2c22616464696e675f7265706c69636173223a7b7d2c2272656d6f76696e675f7265706c69636173223a7b7d7d,s{55,55,1603905757683,1603905757683,0,0,0,0,112,0,55}
2020-10-28 12:22:37.687 DEBUG 27226 --- [XT)-PLAINTEXT-2] kafka.request.logger : Completed request:RequestHeader(apiKey=FIND_COORDINATOR, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=0) -- {key=demo-application,key_type=0,_tagged_fields={}},response:{throttle_time_ms=0,error_code=15,error_message=The coordinator is not available.,node_id=-1,host=,port=-1,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50636-1;totalTime:21.564,requestQueueTime:0.353,localTime:20.855,remoteTime:0.0,throttleTime:0.942,responseQueueTime:0.143,sendTime:0.211,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=apache-kafka-java, softwareVersion=2.5.1)
2020-10-28 12:22:37.687 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Received FindCoordinator response ClientResponse(receivedTimeMs=1603905757687, latencyMs=39, disconnected=false, requestHeader=RequestHeader(apiKey=FIND_COORDINATOR, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=0), responseBody=FindCoordinatorResponseData(throttleTimeMs=0, errorCode=15, errorMessage='The coordinator is not available.', nodeId=-1, host='', port=-1))
2020-10-28 12:22:37.687 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Group coordinator lookup failed: The coordinator is not available.
2020-10-28 12:22:37.687 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Coordinator discovery failed, refreshing metadata
2020-10-28 12:22:37.688 INFO 27226 --- [er-event-thread] kafka.controller.KafkaController : [Controller id=0] New topics: [Set(__consumer_offsets)], deleted topics: [Set()], new partition replica assignment [Map(__consumer_offsets-4 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-3 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-2 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-0 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=), __consumer_offsets-1 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=))]
2020-10-28 12:22:37.688 INFO 27226 --- [er-event-thread] kafka.controller.KafkaController : [Controller id=0] New partition creation callback for __consumer_offsets-4,__consumer_offsets-3,__consumer_offsets-2,__consumer_offsets-0,__consumer_offsets-1
2020-10-28 12:22:37.689 DEBUG 27226 --- [ Test worker] c.DefaultCacheAwareContextLoaderDelegate : Retrieved ApplicationContext [711655536] from cache with key [[MergedContextConfiguration@6f619745 testClass = StreamsConfigurationTest, locations = '{}', classes = '{class com.github.ajablonski.StreamsConfiguration, class com.github.ajablonski.StreamsConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{spring.application.name=demo-application, spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}, org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true}', contextCustomizers = set[org.springframework.kafka.test.context.EmbeddedKafkaContextCustomizer@286523bc, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@53950fea, [ImportsContextCustomizer@7e41aeb8 key = [@org.apiguardian.api.API(consumers={"*"}, since="5.0", status=STABLE), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.kafka.test.condition.EmbeddedKafkaCondition.class}), @org.springframework.boot.autoconfigure.EnableAutoConfiguration(exclude={}, excludeName={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationPackages$Registrar.class}), @org.springframework.test.context.BootstrapWith(value=org.springframework.boot.test.context.SpringBootTestContextBootstrapper.class), @org.springframework.kafka.test.context.EmbeddedKafka(partitions=2, bootstrapServersProperty="", brokerPropertiesLocation="", zookeeperPort=0, topics={"WordCounts", "WordsForNumbers", "OutputTopic"}, controlledShutdown=false, count=1, brokerProperties={}, zkConnectionTimeout=6000, ports={0}, value=1, zkSessionTimeout=6000), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.test.context.junit.jupiter.SpringExtension.class}), @org.springframework.boot.test.context.SpringBootTest(args={}, webEnvironment=MOCK, value={}, properties={"spring.application.name=demo-application", "spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}"}, classes={com.github.ajablonski.StreamsConfiguration.class}), @org.springframework.boot.autoconfigure.AutoConfigurationPackage(basePackages={}, basePackageClasses={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationImportSelector.class})]], org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@412b5795, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@52281bb6, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.web.client.TestRestTemplateContextCustomizer@7b0749e2, org.springframework.boot.test.context.SpringBootTestArgs@1], contextLoader = 'org.springframework.boot.test.context.SpringBootContextLoader', parent = [null]]]
2020-10-28 12:22:37.689 DEBUG 27226 --- [ Test worker] org.springframework.test.context.cache : Spring test ApplicationContext cache statistics: [DefaultContextCache@1bbf537b size = 1, maxSize = 32, parentContextCount = 0, hitCount = 2, missCount = 1]
2020-10-28 12:22:37.690 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.691 DEBUG 27226 --- [ Test worker] c.DefaultCacheAwareContextLoaderDelegate : Retrieved ApplicationContext [711655536] from cache with key [[MergedContextConfiguration@6f619745 testClass = StreamsConfigurationTest, locations = '{}', classes = '{class com.github.ajablonski.StreamsConfiguration, class com.github.ajablonski.StreamsConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{spring.application.name=demo-application, spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}, org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true}', contextCustomizers = set[org.springframework.kafka.test.context.EmbeddedKafkaContextCustomizer@286523bc, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@53950fea, [ImportsContextCustomizer@7e41aeb8 key = [@org.apiguardian.api.API(consumers={"*"}, since="5.0", status=STABLE), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.kafka.test.condition.EmbeddedKafkaCondition.class}), @org.springframework.boot.autoconfigure.EnableAutoConfiguration(exclude={}, excludeName={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationPackages$Registrar.class}), @org.springframework.test.context.BootstrapWith(value=org.springframework.boot.test.context.SpringBootTestContextBootstrapper.class), @org.springframework.kafka.test.context.EmbeddedKafka(partitions=2, bootstrapServersProperty="", brokerPropertiesLocation="", zookeeperPort=0, topics={"WordCounts", "WordsForNumbers", "OutputTopic"}, controlledShutdown=false, count=1, brokerProperties={}, zkConnectionTimeout=6000, ports={0}, value=1, zkSessionTimeout=6000), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.test.context.junit.jupiter.SpringExtension.class}), @org.springframework.boot.test.context.SpringBootTest(args={}, webEnvironment=MOCK, value={}, properties={"spring.application.name=demo-application", "spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}"}, classes={com.github.ajablonski.StreamsConfiguration.class}), @org.springframework.boot.autoconfigure.AutoConfigurationPackage(basePackages={}, basePackageClasses={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationImportSelector.class})]], org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@412b5795, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@52281bb6, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.web.client.TestRestTemplateContextCustomizer@7b0749e2, org.springframework.boot.test.context.SpringBootTestArgs@1], contextLoader = 'org.springframework.boot.test.context.SpringBootContextLoader', parent = [null]]]
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.691 DEBUG 27226 --- [ Test worker] org.springframework.test.context.cache : Spring test ApplicationContext cache statistics: [DefaultContextCache@1bbf537b size = 1, maxSize = 32, parentContextCount = 0, hitCount = 3, missCount = 1]
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.691 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.692 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x6a zxid:0x38 txntype:14 reqpath:n/a
2020-10-28 12:22:37.692 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x6a zxid:0x38 txntype:14 reqpath:n/a
2020-10-28 12:22:37.692 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 106,14 replyHeader:: 106,56,0 request:: org.apache.zookeeper.MultiTransactionRecord@47c7375 response:: org.apache.zookeeper.MultiResponse@fe4873b6
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.693 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.694 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x6b zxid:0x39 txntype:14 reqpath:n/a
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.694 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x6b zxid:0x39 txntype:14 reqpath:n/a
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.694 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 107,14 replyHeader:: 107,57,0 request:: org.apache.zookeeper.MultiTransactionRecord@940352da response:: org.apache.zookeeper.MultiResponse@8dcf531b
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.694 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.695 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x6c zxid:0x3a txntype:14 reqpath:n/a
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.695 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x6c zxid:0x3a txntype:14 reqpath:n/a
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.695 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x6d zxid:0x3b txntype:14 reqpath:n/a
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.695 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 108,14 replyHeader:: 108,58,0 request:: org.apache.zookeeper.MultiTransactionRecord@940352d9 response:: org.apache.zookeeper.MultiResponse@8dcf531a
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.695 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x6d zxid:0x3b txntype:14 reqpath:n/a
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.695 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.696 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 109,14 replyHeader:: 109,59,0 request:: org.apache.zookeeper.MultiTransactionRecord@940352d8 response:: org.apache.zookeeper.MultiResponse@8dcf5319
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.696 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x6e zxid:0x3c txntype:14 reqpath:n/a
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.696 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x6e zxid:0x3c txntype:14 reqpath:n/a
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.696 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.696 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 110,14 replyHeader:: 110,60,0 request:: org.apache.zookeeper.MultiTransactionRecord@940352d6 response:: org.apache.zookeeper.MultiResponse@8dcf5317
2020-10-28 12:22:37.696 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x6f zxid:0x3d txntype:14 reqpath:n/a
2020-10-28 12:22:37.696 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x6f zxid:0x3d txntype:14 reqpath:n/a
2020-10-28 12:22:37.697 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 111,14 replyHeader:: 111,61,0 request:: org.apache.zookeeper.MultiTransactionRecord@940352d7 response:: org.apache.zookeeper.MultiResponse@8dcf5318
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.699 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x70 zxid:0x3e txntype:14 reqpath:n/a
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.699 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.699 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x70 zxid:0x3e txntype:14 reqpath:n/a
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.700 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 112,14 replyHeader:: 112,62,0 request:: org.apache.zookeeper.MultiTransactionRecord@1bd8bcd1 response:: org.apache.zookeeper.MultiResponse@c2bb699d
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.700 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x71 zxid:0x3f txntype:14 reqpath:n/a
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.700 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.700 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x71 zxid:0x3f txntype:14 reqpath:n/a
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.701 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x72 zxid:0x40 txntype:14 reqpath:n/a
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.701 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 113,14 replyHeader:: 113,63,0 request:: org.apache.zookeeper.MultiTransactionRecord@e6f28190 response:: org.apache.zookeeper.MultiResponse@8dd52e5c
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.701 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x72 zxid:0x40 txntype:14 reqpath:n/a
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.701 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x73 zxid:0x41 txntype:14 reqpath:n/a
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.701 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 114,14 replyHeader:: 114,64,0 request:: org.apache.zookeeper.MultiTransactionRecord@b20c464f response:: org.apache.zookeeper.MultiResponse@58eef31b
2020-10-28 12:22:37.701 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.702 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.702 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x73 zxid:0x41 txntype:14 reqpath:n/a
2020-10-28 12:22:37.702 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.702 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Processing ACL: 31,s{'world,'anyone}
2020-10-28 12:22:37.702 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Permission requested: 4
2020-10-28 12:22:37.702 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.702 DEBUG 27226 --- [0 cport:50628):] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.702 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 115,14 replyHeader:: 115,65,0 request:: org.apache.zookeeper.MultiTransactionRecord@483fcfcd response:: org.apache.zookeeper.MultiResponse@ef227c99
2020-10-28 12:22:37.702 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:multi cxid:0x74 zxid:0x42 txntype:14 reqpath:n/a
2020-10-28 12:22:37.702 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:multi cxid:0x74 zxid:0x42 txntype:14 reqpath:n/a
2020-10-28 12:22:37.703 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:null serverPath:null finished:false header:: 116,14 replyHeader:: 116,66,0 request:: org.apache.zookeeper.MultiTransactionRecord@7d260b0e response:: org.apache.zookeeper.MultiResponse@2408b7da
2020-10-28 12:22:37.710 INFO 27226 --- [quest-handler-4] kafka.server.ReplicaFetcherManager : [ReplicaFetcherManager on broker 0] Removed fetcher for partitions Set(__consumer_offsets-4, __consumer_offsets-3, __consumer_offsets-2, __consumer_offsets-0, __consumer_offsets-1)
2020-10-28 12:22:37.710 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.710 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getData cxid:0x75 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.710 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getData cxid:0x75 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.710 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.710 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.711 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.711 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/config/topics/__consumer_offsets serverPath:/config/topics/__consumer_offsets finished:false header:: 117,4 replyHeader:: 117,66,0 request:: '/config/topics/__consumer_offsets,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b22636f6d7072657373696f6e2e74797065223a2270726f6475636572222c22636c65616e75702e706f6c696379223a22636f6d70616374222c227365676d656e742e6279746573223a22313034383537363030227d7d,s{54,54,1603905757681,1603905757681,0,0,0,0,109,0,54}
2020-10-28 12:22:37.715 DEBUG 27226 --- [quest-handler-4] kafka.log.OffsetIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-0/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 0, lastOffset = 0, file position = 0
2020-10-28 12:22:37.715 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-0/00000000000000000000.index was not resized because it already has size 10485760
2020-10-28 12:22:37.715 DEBUG 27226 --- [quest-handler-4] kafka.log.TimeIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-0/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 0, lastOffset = TimestampOffset(-1,0), file position = 0
2020-10-28 12:22:37.715 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-0/00000000000000000000.timeindex was not resized because it already has size 10485756
2020-10-28 12:22:37.716 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-0, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Loading producer state till offset 0 with message format version 2
2020-10-28 12:22:37.717 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-0, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Completed load of log with 1 segments, log start offset 0 and log end offset 0 in 4 ms
2020-10-28 12:22:37.717 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms.
2020-10-28 12:22:37.718 INFO 27226 --- [quest-handler-4] kafka.log.LogManager : Created log for partition __consumer_offsets-0 in /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-0 with properties {compression.type -> producer, min.insync.replicas -> 1, message.downconversion.enable -> true, segment.jitter.ms -> 0, cleanup.policy -> compact, flush.ms -> 9223372036854775807, retention.ms -> 604800000, segment.bytes -> 104857600, flush.messages -> 9223372036854775807, message.format.version -> 2.5-IV0, max.compaction.lag.ms -> 9223372036854775807, file.delete.delay.ms -> 1000, max.message.bytes -> 1048588, min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime, preallocate -> false, index.interval.bytes -> 4096, min.cleanable.dirty.ratio -> 0.5, unclean.leader.election.enable -> false, retention.bytes -> -1, delete.retention.ms -> 86400000, segment.ms -> 604800000, message.timestamp.difference.max.ms -> 9223372036854775807, segment.index.bytes -> 10485760}.
2020-10-28 12:22:37.718 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-0 broker=0] No checkpointed highwatermark is found for partition __consumer_offsets-0
2020-10-28 12:22:37.718 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-0 broker=0] Log loaded for partition __consumer_offsets-0 with initial high watermark 0
2020-10-28 12:22:37.718 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-0 broker=0] __consumer_offsets-0 starts at leader epoch 0 from offset 0 with high watermark 0. Previous leader epoch was -1.
2020-10-28 12:22:37.718 DEBUG 27226 --- [quest-handler-4] kafka.server.epoch.LeaderEpochFileCache : [LeaderEpochCache __consumer_offsets-0] Appended new epoch entry EpochEntry(epoch=0, startOffset=0). Cache now contains 1 entries.
2020-10-28 12:22:37.720 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.720 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getData cxid:0x76 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.720 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getData cxid:0x76 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.720 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.720 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.720 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.720 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/config/topics/__consumer_offsets serverPath:/config/topics/__consumer_offsets finished:false header:: 118,4 replyHeader:: 118,66,0 request:: '/config/topics/__consumer_offsets,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b22636f6d7072657373696f6e2e74797065223a2270726f6475636572222c22636c65616e75702e706f6c696379223a22636f6d70616374222c227365676d656e742e6279746573223a22313034383537363030227d7d,s{54,54,1603905757681,1603905757681,0,0,0,0,109,0,54}
2020-10-28 12:22:37.723 DEBUG 27226 --- [quest-handler-4] kafka.log.OffsetIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-4/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 0, lastOffset = 0, file position = 0
2020-10-28 12:22:37.724 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-4/00000000000000000000.index was not resized because it already has size 10485760
2020-10-28 12:22:37.725 DEBUG 27226 --- [quest-handler-4] kafka.log.TimeIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-4/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 0, lastOffset = TimestampOffset(-1,0), file position = 0
2020-10-28 12:22:37.725 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-4/00000000000000000000.timeindex was not resized because it already has size 10485756
2020-10-28 12:22:37.725 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-4, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Loading producer state till offset 0 with message format version 2
2020-10-28 12:22:37.726 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-4, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Completed load of log with 1 segments, log start offset 0 and log end offset 0 in 4 ms
2020-10-28 12:22:37.726 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms.
2020-10-28 12:22:37.727 INFO 27226 --- [quest-handler-4] kafka.log.LogManager : Created log for partition __consumer_offsets-4 in /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-4 with properties {compression.type -> producer, min.insync.replicas -> 1, message.downconversion.enable -> true, segment.jitter.ms -> 0, cleanup.policy -> compact, flush.ms -> 9223372036854775807, retention.ms -> 604800000, segment.bytes -> 104857600, flush.messages -> 9223372036854775807, message.format.version -> 2.5-IV0, max.compaction.lag.ms -> 9223372036854775807, file.delete.delay.ms -> 1000, max.message.bytes -> 1048588, min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime, preallocate -> false, index.interval.bytes -> 4096, min.cleanable.dirty.ratio -> 0.5, unclean.leader.election.enable -> false, retention.bytes -> -1, delete.retention.ms -> 86400000, segment.ms -> 604800000, message.timestamp.difference.max.ms -> 9223372036854775807, segment.index.bytes -> 10485760}.
2020-10-28 12:22:37.727 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-4 broker=0] No checkpointed highwatermark is found for partition __consumer_offsets-4
2020-10-28 12:22:37.727 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-4 broker=0] Log loaded for partition __consumer_offsets-4 with initial high watermark 0
2020-10-28 12:22:37.727 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-4 broker=0] __consumer_offsets-4 starts at leader epoch 0 from offset 0 with high watermark 0. Previous leader epoch was -1.
2020-10-28 12:22:37.727 DEBUG 27226 --- [quest-handler-4] kafka.server.epoch.LeaderEpochFileCache : [LeaderEpochCache __consumer_offsets-4] Appended new epoch entry EpochEntry(epoch=0, startOffset=0). Cache now contains 1 entries.
2020-10-28 12:22:37.729 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.729 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getData cxid:0x77 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.729 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getData cxid:0x77 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.729 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.729 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.730 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.730 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/config/topics/__consumer_offsets serverPath:/config/topics/__consumer_offsets finished:false header:: 119,4 replyHeader:: 119,66,0 request:: '/config/topics/__consumer_offsets,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b22636f6d7072657373696f6e2e74797065223a2270726f6475636572222c22636c65616e75702e706f6c696379223a22636f6d70616374222c227365676d656e742e6279746573223a22313034383537363030227d7d,s{54,54,1603905757681,1603905757681,0,0,0,0,109,0,54}
2020-10-28 12:22:37.735 DEBUG 27226 --- [quest-handler-4] kafka.log.OffsetIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-1/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 0, lastOffset = 0, file position = 0
2020-10-28 12:22:37.735 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-1/00000000000000000000.index was not resized because it already has size 10485760
2020-10-28 12:22:37.735 DEBUG 27226 --- [quest-handler-4] kafka.log.TimeIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-1/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 0, lastOffset = TimestampOffset(-1,0), file position = 0
2020-10-28 12:22:37.735 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-1/00000000000000000000.timeindex was not resized because it already has size 10485756
2020-10-28 12:22:37.736 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-1, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Loading producer state till offset 0 with message format version 2
2020-10-28 12:22:37.737 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-1, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Completed load of log with 1 segments, log start offset 0 and log end offset 0 in 4 ms
2020-10-28 12:22:37.737 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms.
2020-10-28 12:22:37.738 INFO 27226 --- [quest-handler-4] kafka.log.LogManager : Created log for partition __consumer_offsets-1 in /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-1 with properties {compression.type -> producer, min.insync.replicas -> 1, message.downconversion.enable -> true, segment.jitter.ms -> 0, cleanup.policy -> compact, flush.ms -> 9223372036854775807, retention.ms -> 604800000, segment.bytes -> 104857600, flush.messages -> 9223372036854775807, message.format.version -> 2.5-IV0, max.compaction.lag.ms -> 9223372036854775807, file.delete.delay.ms -> 1000, max.message.bytes -> 1048588, min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime, preallocate -> false, index.interval.bytes -> 4096, min.cleanable.dirty.ratio -> 0.5, unclean.leader.election.enable -> false, retention.bytes -> -1, delete.retention.ms -> 86400000, segment.ms -> 604800000, message.timestamp.difference.max.ms -> 9223372036854775807, segment.index.bytes -> 10485760}.
2020-10-28 12:22:37.738 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-1 broker=0] No checkpointed highwatermark is found for partition __consumer_offsets-1
2020-10-28 12:22:37.738 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-1 broker=0] Log loaded for partition __consumer_offsets-1 with initial high watermark 0
2020-10-28 12:22:37.738 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-1 broker=0] __consumer_offsets-1 starts at leader epoch 0 from offset 0 with high watermark 0. Previous leader epoch was -1.
2020-10-28 12:22:37.738 DEBUG 27226 --- [quest-handler-4] kafka.server.epoch.LeaderEpochFileCache : [LeaderEpochCache __consumer_offsets-1] Appended new epoch entry EpochEntry(epoch=0, startOffset=0). Cache now contains 1 entries.
2020-10-28 12:22:37.740 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.740 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getData cxid:0x78 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.740 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getData cxid:0x78 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.740 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.740 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.741 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.741 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/config/topics/__consumer_offsets serverPath:/config/topics/__consumer_offsets finished:false header:: 120,4 replyHeader:: 120,66,0 request:: '/config/topics/__consumer_offsets,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b22636f6d7072657373696f6e2e74797065223a2270726f6475636572222c22636c65616e75702e706f6c696379223a22636f6d70616374222c227365676d656e742e6279746573223a22313034383537363030227d7d,s{54,54,1603905757681,1603905757681,0,0,0,0,109,0,54}
2020-10-28 12:22:37.746 DEBUG 27226 --- [quest-handler-4] kafka.log.OffsetIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-2/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 0, lastOffset = 0, file position = 0
2020-10-28 12:22:37.746 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-2/00000000000000000000.index was not resized because it already has size 10485760
2020-10-28 12:22:37.747 DEBUG 27226 --- [quest-handler-4] kafka.log.TimeIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-2/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 0, lastOffset = TimestampOffset(-1,0), file position = 0
2020-10-28 12:22:37.747 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-2/00000000000000000000.timeindex was not resized because it already has size 10485756
2020-10-28 12:22:37.747 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-2, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Loading producer state till offset 0 with message format version 2
2020-10-28 12:22:37.748 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-2, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Completed load of log with 1 segments, log start offset 0 and log end offset 0 in 4 ms
2020-10-28 12:22:37.748 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms.
2020-10-28 12:22:37.749 INFO 27226 --- [quest-handler-4] kafka.log.LogManager : Created log for partition __consumer_offsets-2 in /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-2 with properties {compression.type -> producer, min.insync.replicas -> 1, message.downconversion.enable -> true, segment.jitter.ms -> 0, cleanup.policy -> compact, flush.ms -> 9223372036854775807, retention.ms -> 604800000, segment.bytes -> 104857600, flush.messages -> 9223372036854775807, message.format.version -> 2.5-IV0, max.compaction.lag.ms -> 9223372036854775807, file.delete.delay.ms -> 1000, max.message.bytes -> 1048588, min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime, preallocate -> false, index.interval.bytes -> 4096, min.cleanable.dirty.ratio -> 0.5, unclean.leader.election.enable -> false, retention.bytes -> -1, delete.retention.ms -> 86400000, segment.ms -> 604800000, message.timestamp.difference.max.ms -> 9223372036854775807, segment.index.bytes -> 10485760}.
2020-10-28 12:22:37.749 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-2 broker=0] No checkpointed highwatermark is found for partition __consumer_offsets-2
2020-10-28 12:22:37.749 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-2 broker=0] Log loaded for partition __consumer_offsets-2 with initial high watermark 0
2020-10-28 12:22:37.749 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-2 broker=0] __consumer_offsets-2 starts at leader epoch 0 from offset 0 with high watermark 0. Previous leader epoch was -1.
2020-10-28 12:22:37.749 DEBUG 27226 --- [quest-handler-4] kafka.server.epoch.LeaderEpochFileCache : [LeaderEpochCache __consumer_offsets-2] Appended new epoch entry EpochEntry(epoch=0, startOffset=0). Cache now contains 1 entries.
2020-10-28 12:22:37.751 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.751 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getData cxid:0x79 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.751 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getData cxid:0x79 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/__consumer_offsets
2020-10-28 12:22:37.751 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.751 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.751 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.752 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/config/topics/__consumer_offsets serverPath:/config/topics/__consumer_offsets finished:false header:: 121,4 replyHeader:: 121,66,0 request:: '/config/topics/__consumer_offsets,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b22636f6d7072657373696f6e2e74797065223a2270726f6475636572222c22636c65616e75702e706f6c696379223a22636f6d70616374222c227365676d656e742e6279746573223a22313034383537363030227d7d,s{54,54,1603905757681,1603905757681,0,0,0,0,109,0,54}
2020-10-28 12:22:37.755 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Sending FindCoordinator request to broker localhost:50630 (id: 0 rack: null)
2020-10-28 12:22:37.755 DEBUG 27226 --- [quest-handler-4] kafka.log.OffsetIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-3/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 0, lastOffset = 0, file position = 0
2020-10-28 12:22:37.755 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-3/00000000000000000000.index was not resized because it already has size 10485760
2020-10-28 12:22:37.755 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Initiating connection to node localhost:50630 (id: 0 rack: null) using address localhost/127.0.0.1
2020-10-28 12:22:37.756 DEBUG 27226 --- [quest-handler-4] kafka.log.TimeIndex : Loaded index file /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-3/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 0, lastOffset = TimestampOffset(-1,0), file position = 0
2020-10-28 12:22:37.756 DEBUG 27226 --- [quest-handler-4] kafka.log.AbstractIndex : Index /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-3/00000000000000000000.timeindex was not resized because it already has size 10485756
2020-10-28 12:22:37.756 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-3, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Loading producer state till offset 0 with message format version 2
2020-10-28 12:22:37.756 DEBUG 27226 --- [-StreamThread-1] o.apache.kafka.common.network.Selector : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Created socket with SO_RCVBUF = 342972, SO_SNDBUF = 146988, SO_TIMEOUT = 0 to node 0
2020-10-28 12:22:37.756 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Completed connection to node 0. Fetching API versions.
2020-10-28 12:22:37.756 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Initiating API versions fetch from node 0.
2020-10-28 12:22:37.756 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.network.Processor : Processor 0 listening to new connection from /127.0.0.1:50637
2020-10-28 12:22:37.756 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.network.Acceptor : Accepted connection from /127.0.0.1:50637 on /127.0.0.1:50630 and assigned it to processor 0, sendBufferSize [actual|requested]: [102400|102400] recvBufferSize [actual|requested]: [375636|102400]
2020-10-28 12:22:37.757 INFO 27226 --- [quest-handler-4] kafka.log.Log : [Log partition=__consumer_offsets-3, dir=/var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743] Completed load of log with 1 segments, log start offset 0 and log end offset 0 in 4 ms
2020-10-28 12:22:37.758 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms.
2020-10-28 12:22:37.758 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.request.logger : Completed request:RequestHeader(apiKey=API_VERSIONS, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=4) -- {client_software_name=apache-kafka-java,client_software_version=2.5.1,_tagged_fields={}},response:{error_code=0,api_keys=[{api_key=0,min_version=0,max_version=8,_tagged_fields={}},{api_key=1,min_version=0,max_version=11,_tagged_fields={}},{api_key=2,min_version=0,max_version=5,_tagged_fields={}},{api_key=3,min_version=0,max_version=9,_tagged_fields={}},{api_key=4,min_version=0,max_version=4,_tagged_fields={}},{api_key=5,min_version=0,max_version=2,_tagged_fields={}},{api_key=6,min_version=0,max_version=6,_tagged_fields={}},{api_key=7,min_version=0,max_version=3,_tagged_fields={}},{api_key=8,min_version=0,max_version=8,_tagged_fields={}},{api_key=9,min_version=0,max_version=7,_tagged_fields={}},{api_key=10,min_version=0,max_version=3,_tagged_fields={}},{api_key=11,min_version=0,max_version=7,_tagged_fields={}},{api_key=12,min_version=0,max_version=4,_tagged_fields={}},{api_key=13,min_version=0,max_version=4,_tagged_fields={}},{api_key=14,min_version=0,max_version=5,_tagged_fields={}},{api_key=15,min_version=0,max_version=5,_tagged_fields={}},{api_key=16,min_version=0,max_version=3,_tagged_fields={}},{api_key=17,min_version=0,max_version=1,_tagged_fields={}},{api_key=18,min_version=0,max_version=3,_tagged_fields={}},{api_key=19,min_version=0,max_version=5,_tagged_fields={}},{api_key=20,min_version=0,max_version=4,_tagged_fields={}},{api_key=21,min_version=0,max_version=1,_tagged_fields={}},{api_key=22,min_version=0,max_version=3,_tagged_fields={}},{api_key=23,min_version=0,max_version=3,_tagged_fields={}},{api_key=24,min_version=0,max_version=1,_tagged_fields={}},{api_key=25,min_version=0,max_version=1,_tagged_fields={}},{api_key=26,min_version=0,max_version=1,_tagged_fields={}},{api_key=27,min_version=0,max_version=0,_tagged_fields={}},{api_key=28,min_version=0,max_version=3,_tagged_fields={}},{api_key=29,min_version=0,max_version=2,_tagged_fields={}},{api_key=30,min_version=0,max_version=2,_tagged_fields={}},{api_key=31,min_version=0,max_version=2,_tagged_fields={}},{api_key=32,min_version=0,max_version=2,_tagged_fields={}},{api_key=33,min_version=0,max_version=1,_tagged_fields={}},{api_key=34,min_version=0,max_version=1,_tagged_fields={}},{api_key=35,min_version=0,max_version=1,_tagged_fields={}},{api_key=36,min_version=0,max_version=2,_tagged_fields={}},{api_key=37,min_version=0,max_version=2,_tagged_fields={}},{api_key=38,min_version=0,max_version=2,_tagged_fields={}},{api_key=39,min_version=0,max_version=2,_tagged_fields={}},{api_key=40,min_version=0,max_version=2,_tagged_fields={}},{api_key=41,min_version=0,max_version=2,_tagged_fields={}},{api_key=42,min_version=0,max_version=2,_tagged_fields={}},{api_key=43,min_version=0,max_version=2,_tagged_fields={}},{api_key=44,min_version=0,max_version=1,_tagged_fields={}},{api_key=45,min_version=0,max_version=0,_tagged_fields={}},{api_key=46,min_version=0,max_version=0,_tagged_fields={}},{api_key=47,min_version=0,max_version=0,_tagged_fields={}}],throttle_time_ms=0,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50637-2;totalTime:0.747,requestQueueTime:0.175,localTime:0.316,remoteTime:0.0,throttleTime:0.288,responseQueueTime:0.076,sendTime:0.179,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=unknown, softwareVersion=unknown)
2020-10-28 12:22:37.758 INFO 27226 --- [quest-handler-4] kafka.log.LogManager : Created log for partition __consumer_offsets-3 in /var/folders/j6/95t86kgx4qs9dj_55r0vymcm0000gn/T/spring.kafka.95eb33af-ba41-441b-b183-9e309d36a70d7792793805006277743/__consumer_offsets-3 with properties {compression.type -> producer, min.insync.replicas -> 1, message.downconversion.enable -> true, segment.jitter.ms -> 0, cleanup.policy -> compact, flush.ms -> 9223372036854775807, retention.ms -> 604800000, segment.bytes -> 104857600, flush.messages -> 9223372036854775807, message.format.version -> 2.5-IV0, max.compaction.lag.ms -> 9223372036854775807, file.delete.delay.ms -> 1000, max.message.bytes -> 1048588, min.compaction.lag.ms -> 0, message.timestamp.type -> CreateTime, preallocate -> false, index.interval.bytes -> 4096, min.cleanable.dirty.ratio -> 0.5, unclean.leader.election.enable -> false, retention.bytes -> -1, delete.retention.ms -> 86400000, segment.ms -> 604800000, message.timestamp.difference.max.ms -> 9223372036854775807, segment.index.bytes -> 10485760}.
2020-10-28 12:22:37.758 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-3 broker=0] No checkpointed highwatermark is found for partition __consumer_offsets-3
2020-10-28 12:22:37.758 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-3 broker=0] Log loaded for partition __consumer_offsets-3 with initial high watermark 0
2020-10-28 12:22:37.758 INFO 27226 --- [quest-handler-4] kafka.cluster.Partition : [Partition __consumer_offsets-3 broker=0] __consumer_offsets-3 starts at leader epoch 0 from offset 0 with high watermark 0. Previous leader epoch was -1.
2020-10-28 12:22:37.758 DEBUG 27226 --- [quest-handler-4] kafka.server.epoch.LeaderEpochFileCache : [LeaderEpochCache __consumer_offsets-3] Appended new epoch entry EpochEntry(epoch=0, startOffset=0). Cache now contains 1 entries.
2020-10-28 12:22:37.758 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Recorded API versions for node 0: (Produce(0): 0 to 8 [usable: 8], Fetch(1): 0 to 11 [usable: 11], ListOffsets(2): 0 to 5 [usable: 5], Metadata(3): 0 to 9 [usable: 9], LeaderAndIsr(4): 0 to 4 [usable: 4], StopReplica(5): 0 to 2 [usable: 2], UpdateMetadata(6): 0 to 6 [usable: 6], ControlledShutdown(7): 0 to 3 [usable: 3], OffsetCommit(8): 0 to 8 [usable: 8], OffsetFetch(9): 0 to 7 [usable: 7], FindCoordinator(10): 0 to 3 [usable: 3], JoinGroup(11): 0 to 7 [usable: 7], Heartbeat(12): 0 to 4 [usable: 4], LeaveGroup(13): 0 to 4 [usable: 4], SyncGroup(14): 0 to 5 [usable: 5], DescribeGroups(15): 0 to 5 [usable: 5], ListGroups(16): 0 to 3 [usable: 3], SaslHandshake(17): 0 to 1 [usable: 1], ApiVersions(18): 0 to 3 [usable: 3], CreateTopics(19): 0 to 5 [usable: 5], DeleteTopics(20): 0 to 4 [usable: 4], DeleteRecords(21): 0 to 1 [usable: 1], InitProducerId(22): 0 to 3 [usable: 3], OffsetForLeaderEpoch(23): 0 to 3 [usable: 3], AddPartitionsToTxn(24): 0 to 1 [usable: 1], AddOffsetsToTxn(25): 0 to 1 [usable: 1], EndTxn(26): 0 to 1 [usable: 1], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 to 3 [usable: 3], DescribeAcls(29): 0 to 2 [usable: 2], CreateAcls(30): 0 to 2 [usable: 2], DeleteAcls(31): 0 to 2 [usable: 2], DescribeConfigs(32): 0 to 2 [usable: 2], AlterConfigs(33): 0 to 1 [usable: 1], AlterReplicaLogDirs(34): 0 to 1 [usable: 1], DescribeLogDirs(35): 0 to 1 [usable: 1], SaslAuthenticate(36): 0 to 2 [usable: 2], CreatePartitions(37): 0 to 2 [usable: 2], CreateDelegationToken(38): 0 to 2 [usable: 2], RenewDelegationToken(39): 0 to 2 [usable: 2], ExpireDelegationToken(40): 0 to 2 [usable: 2], DescribeDelegationToken(41): 0 to 2 [usable: 2], DeleteGroups(42): 0 to 2 [usable: 2], ElectLeaders(43): 0 to 2 [usable: 2], IncrementalAlterConfigs(44): 0 to 1 [usable: 1], AlterPartitionReassignments(45): 0 [usable: 0], ListPartitionReassignments(46): 0 [usable: 0], OffsetDelete(47): 0 [usable: 0])
2020-10-28 12:22:37.759 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.760 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getChildren2 cxid:0x7a zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids
2020-10-28 12:22:37.760 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getChildren2 cxid:0x7a zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids
2020-10-28 12:22:37.760 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.760 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.760 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.760 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/brokers/ids serverPath:/brokers/ids finished:false header:: 122,12 replyHeader:: 122,66,0 request:: '/brokers/ids,T response:: v{'0},s{5,5,1603905755452,1603905755452,0,1,0,0,0,1,24}
2020-10-28 12:22:37.761 INFO 27226 --- [quest-handler-4] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Scheduling loading of offsets and group metadata from __consumer_offsets-3
2020-10-28 12:22:37.761 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task __consumer_offsets-3 with initial delay 0 ms and period -1 ms.
2020-10-28 12:22:37.762 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.762 INFO 27226 --- [quest-handler-4] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Scheduling loading of offsets and group metadata from __consumer_offsets-2
2020-10-28 12:22:37.762 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:getData cxid:0x7b zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids/0
2020-10-28 12:22:37.762 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:getData cxid:0x7b zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids/0
2020-10-28 12:22:37.762 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task __consumer_offsets-2 with initial delay 0 ms and period -1 ms.
2020-10-28 12:22:37.762 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Permission requested: 1
2020-10-28 12:22:37.762 INFO 27226 --- [quest-handler-4] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Scheduling loading of offsets and group metadata from __consumer_offsets-1
2020-10-28 12:22:37.762 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : ACLs for node: [31,s{'world,'anyone}
]
2020-10-28 12:22:37.762 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.PrepRequestProcessor : Client credentials: ['ip,'127.0.0.1
]
2020-10-28 12:22:37.762 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task __consumer_offsets-1 with initial delay 0 ms and period -1 ms.
2020-10-28 12:22:37.762 INFO 27226 --- [quest-handler-4] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Scheduling loading of offsets and group metadata from __consumer_offsets-4
2020-10-28 12:22:37.762 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task __consumer_offsets-4 with initial delay 0 ms and period -1 ms.
2020-10-28 12:22:37.762 INFO 27226 --- [quest-handler-4] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Scheduling loading of offsets and group metadata from __consumer_offsets-0
2020-10-28 12:22:37.762 DEBUG 27226 --- [quest-handler-4] kafka.utils.KafkaScheduler : Scheduling task __consumer_offsets-0 with initial delay 0 ms and period -1 ms.
2020-10-28 12:22:37.762 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/brokers/ids/0 serverPath:/brokers/ids/0 finished:false header:: 123,4 replyHeader:: 123,66,0 request:: '/brokers/ids/0,T response:: #7b226c697374656e65725f73656375726974795f70726f746f636f6c5f6d6170223a7b22504c41494e54455854223a22504c41494e54455854227d2c22656e64706f696e7473223a5b22504c41494e544558543a2f2f6c6f63616c686f73743a3530363330225d2c226a6d785f706f7274223a2d312c22686f7374223a226c6f63616c686f7374222c2274696d657374616d70223a2231363033393035373536313836222c22706f7274223a35303633302c2276657273696f6e223a347d,s{24,24,1603905756204,1603905756204,1,0,0,72076852269023232,190,0,24}
2020-10-28 12:22:37.763 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.request.logger : Completed request:RequestHeader(apiKey=LEADER_AND_ISR, apiVersion=4, clientId=0, correlationId=5) -- {controller_id=0,controller_epoch=1,broker_epoch=24,topic_states=[{topic_name=__consumer_offsets,partition_states=[{partition_index=2,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],adding_replicas=[],removing_replicas=[],is_new=true,_tagged_fields={}},{partition_index=4,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],adding_replicas=[],removing_replicas=[],is_new=true,_tagged_fields={}},{partition_index=1,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],adding_replicas=[],removing_replicas=[],is_new=true,_tagged_fields={}},{partition_index=3,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],adding_replicas=[],removing_replicas=[],is_new=true,_tagged_fields={}},{partition_index=0,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],adding_replicas=[],removing_replicas=[],is_new=true,_tagged_fields={}}],_tagged_fields={}}],live_leaders=[{broker_id=0,host_name=localhost,port=50630,_tagged_fields={}}],_tagged_fields={}},response:{error_code=0,partition_errors=[{topic_name=__consumer_offsets,partition_index=2,error_code=0,_tagged_fields={}},{topic_name=__consumer_offsets,partition_index=4,error_code=0,_tagged_fields={}},{topic_name=__consumer_offsets,partition_index=1,error_code=0,_tagged_fields={}},{topic_name=__consumer_offsets,partition_index=3,error_code=0,_tagged_fields={}},{topic_name=__consumer_offsets,partition_index=0,error_code=0,_tagged_fields={}}],_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50631-0;totalTime:56.893,requestQueueTime:0.172,localTime:56.421,remoteTime:0.0,throttleTime:0.0,responseQueueTime:0.096,sendTime:0.203,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=unknown, softwareVersion=unknown)
2020-10-28 12:22:37.764 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:37.764 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:exists cxid:0x7c zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/__consumer_offsets
2020-10-28 12:22:37.764 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:exists cxid:0x7c zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/__consumer_offsets
2020-10-28 12:22:37.764 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Reading reply sessionid:0x1001183e8060000, packet:: clientPath:/brokers/topics/__consumer_offsets serverPath:/brokers/topics/__consumer_offsets finished:false header:: 124,3 replyHeader:: 124,66,0 request:: '/brokers/topics/__consumer_offsets,T response:: s{55,55,1603905757683,1603905757683,0,1,0,0,112,1,56}
2020-10-28 12:22:37.765 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.request.logger : Completed request:RequestHeader(apiKey=FIND_COORDINATOR, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=3) -- {key=demo-application,key_type=0,_tagged_fields={}},response:{throttle_time_ms=0,error_code=15,error_message=The coordinator is not available.,node_id=-1,host=,port=-1,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50637-2;totalTime:5.958,requestQueueTime:0.081,localTime:5.687,remoteTime:0.0,throttleTime:0.087,responseQueueTime:0.064,sendTime:0.124,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=apache-kafka-java, softwareVersion=2.5.1)
2020-10-28 12:22:37.765 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Received FindCoordinator response ClientResponse(receivedTimeMs=1603905757765, latencyMs=10, disconnected=false, requestHeader=RequestHeader(apiKey=FIND_COORDINATOR, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=3), responseBody=FindCoordinatorResponseData(throttleTimeMs=0, errorCode=15, errorMessage='The coordinator is not available.', nodeId=-1, host='', port=-1))
2020-10-28 12:22:37.765 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Group coordinator lookup failed: The coordinator is not available.
2020-10-28 12:22:37.765 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Coordinator discovery failed, refreshing metadata
2020-10-28 12:22:37.765 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Sending metadata request MetadataRequestData(topics=[MetadataRequestTopic(name='WordCounts'), MetadataRequestTopic(name='demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic'), MetadataRequestTopic(name='WordsForNumbers'), MetadataRequestTopic(name='demo-application-GroupName-repartition'), MetadataRequestTopic(name='demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic')], allowAutoTopicCreation=false, includeClusterAuthorizedOperations=false, includeTopicAuthorizedOperations=false) to node localhost:50630 (id: 0 rack: null)
2020-10-28 12:22:37.766 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.request.logger : Completed request:RequestHeader(apiKey=UPDATE_METADATA, apiVersion=6, clientId=0, correlationId=6) -- {controller_id=0,controller_epoch=1,broker_epoch=24,topic_states=[{topic_name=__consumer_offsets,partition_states=[{partition_index=2,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],offline_replicas=[],_tagged_fields={}},{partition_index=4,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],offline_replicas=[],_tagged_fields={}},{partition_index=1,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],offline_replicas=[],_tagged_fields={}},{partition_index=3,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],offline_replicas=[],_tagged_fields={}},{partition_index=0,controller_epoch=1,leader=0,leader_epoch=0,isr=[0],zk_version=0,replicas=[0],offline_replicas=[],_tagged_fields={}}],_tagged_fields={}}],live_brokers=[{id=0,endpoints=[{port=50630,host=localhost,listener=PLAINTEXT,security_protocol=0,_tagged_fields={}}],rack=null,_tagged_fields={}}],_tagged_fields={}},response:{error_code=0,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50631-0;totalTime:1.148,requestQueueTime:0.196,localTime:0.435,remoteTime:0.0,throttleTime:0.0,responseQueueTime:0.302,sendTime:0.214,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=unknown, softwareVersion=unknown)
2020-10-28 12:22:37.766 INFO 27226 --- [adata-manager-0] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Finished loading offsets and group metadata from __consumer_offsets-3 in 3 milliseconds.
2020-10-28 12:22:37.766 INFO 27226 --- [adata-manager-0] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Finished loading offsets and group metadata from __consumer_offsets-2 in 0 milliseconds.
2020-10-28 12:22:37.766 INFO 27226 --- [adata-manager-0] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Finished loading offsets and group metadata from __consumer_offsets-1 in 0 milliseconds.
2020-10-28 12:22:37.767 INFO 27226 --- [adata-manager-0] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Finished loading offsets and group metadata from __consumer_offsets-4 in 0 milliseconds.
2020-10-28 12:22:37.767 INFO 27226 --- [adata-manager-0] k.c.group.GroupMetadataManager : [GroupMetadataManager brokerId=0] Finished loading offsets and group metadata from __consumer_offsets-0 in 0 milliseconds.
2020-10-28 12:22:37.768 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.request.logger : Completed request:RequestHeader(apiKey=METADATA, apiVersion=9, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=5) -- {topics=[{name=WordCounts,_tagged_fields={}},{name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic,_tagged_fields={}},{name=WordsForNumbers,_tagged_fields={}},{name=demo-application-GroupName-repartition,_tagged_fields={}},{name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic,_tagged_fields={}}],allow_auto_topic_creation=false,include_cluster_authorized_operations=false,include_topic_authorized_operations=false,_tagged_fields={}},response:{throttle_time_ms=0,brokers=[{node_id=0,host=localhost,port=50630,rack=null,_tagged_fields={}}],cluster_id=N7jaHn0uT--Z2F-IG9Te3g,controller_id=0,topics=[{error_code=0,name=WordsForNumbers,is_internal=false,partitions=[{error_code=0,partition_index=0,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}},{error_code=0,partition_index=1,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}}],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=0,name=WordCounts,is_internal=false,partitions=[{error_code=0,partition_index=0,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}},{error_code=0,partition_index=1,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}}],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=3,name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic,is_internal=false,partitions=[],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=3,name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic,is_internal=false,partitions=[],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=3,name=demo-application-GroupName-repartition,is_internal=false,partitions=[],topic_authorized_operations=-2147483648,_tagged_fields={}}],cluster_authorized_operations=-2147483648,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50637-2;totalTime:1.725,requestQueueTime:0.115,localTime:1.264,remoteTime:0.0,throttleTime:0.433,responseQueueTime:0.098,sendTime:0.246,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=apache-kafka-java, softwareVersion=2.5.1)
2020-10-28 12:22:37.768 WARN 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Error while fetching metadata with correlation id 5 : {demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic=UNKNOWN_TOPIC_OR_PARTITION, demo-application-GroupName-repartition=UNKNOWN_TOPIC_OR_PARTITION, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic=UNKNOWN_TOPIC_OR_PARTITION}
2020-10-28 12:22:37.768 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordsForNumbers-0 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.768 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordsForNumbers-1 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.768 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordCounts-0 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.768 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordCounts-1 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.768 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Requesting metadata update for topic demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic due to error UNKNOWN_TOPIC_OR_PARTITION
2020-10-28 12:22:37.768 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Requesting metadata update for topic demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic due to error UNKNOWN_TOPIC_OR_PARTITION
2020-10-28 12:22:37.768 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Requesting metadata update for topic demo-application-GroupName-repartition due to error UNKNOWN_TOPIC_OR_PARTITION
2020-10-28 12:22:37.769 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updated cluster metadata updateVersion 3 to MetadataCache{clusterId='N7jaHn0uT--Z2F-IG9Te3g', nodes={0=localhost:50630 (id: 0 rack: null)}, partitions=[PartitionMetadata(, error=NONE, partition=WordCounts-1, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=), PartitionMetadata(, error=NONE, partition=WordCounts-0, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=), PartitionMetadata(, error=NONE, partition=WordsForNumbers-0, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=), PartitionMetadata(, error=NONE, partition=WordsForNumbers-1, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=)], controller=localhost:50630 (id: 0 rack: null)}
2020-10-28 12:22:37.769 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Sending FindCoordinator request to broker localhost:50630 (id: 0 rack: null)
2020-10-28 12:22:37.771 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.request.logger : Completed request:RequestHeader(apiKey=FIND_COORDINATOR, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=6) -- {key=demo-application,key_type=0,_tagged_fields={}},response:{throttle_time_ms=0,error_code=0,error_message=NONE,node_id=0,host=localhost,port=50630,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50637-2;totalTime:1.56,requestQueueTime:0.134,localTime:1.144,remoteTime:0.0,throttleTime:0.811,responseQueueTime:0.1,sendTime:0.181,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=apache-kafka-java, softwareVersion=2.5.1)
2020-10-28 12:22:37.771 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Received FindCoordinator response ClientResponse(receivedTimeMs=1603905757771, latencyMs=2, disconnected=false, requestHeader=RequestHeader(apiKey=FIND_COORDINATOR, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=6), responseBody=FindCoordinatorResponseData(throttleTimeMs=0, errorCode=0, errorMessage='NONE', nodeId=0, host='localhost', port=50630))
2020-10-28 12:22:37.771 INFO 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Discovered group coordinator localhost:50630 (id: 2147483647 rack: null)
2020-10-28 12:22:37.771 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Initiating connection to node localhost:50630 (id: 2147483647 rack: null) using address localhost/127.0.0.1
2020-10-28 12:22:37.772 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.network.Acceptor : Accepted connection from /127.0.0.1:50638 on /127.0.0.1:50630 and assigned it to processor 1, sendBufferSize [actual|requested]: [102400|102400] recvBufferSize [actual|requested]: [375636|102400]
2020-10-28 12:22:37.772 DEBUG 27226 --- [XT)-PLAINTEXT-1] kafka.network.Processor : Processor 1 listening to new connection from /127.0.0.1:50638
2020-10-28 12:22:37.774 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.ConsumerCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Executing onJoinPrepare with generation -1 and memberId
2020-10-28 12:22:37.774 DEBUG 27226 --- [emo-application] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Heartbeat thread started
2020-10-28 12:22:37.774 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Disabling heartbeat thread
2020-10-28 12:22:37.774 INFO 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] (Re-)joining group
2020-10-28 12:22:37.775 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.ConsumerCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Joining group with current subscription: [WordCounts, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic, WordsForNumbers, demo-application-GroupName-repartition, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic]
2020-10-28 12:22:37.776 DEBUG 27226 --- [-StreamThread-1] o.a.k.s.p.i.InternalTopologyBuilder : Found pattern subscribed source topics, falling back to pattern subscription for the main consumer.
2020-10-28 12:22:37.776 DEBUG 27226 --- [-StreamThread-1] o.a.k.s.p.i.InternalTopologyBuilder : stream-thread [demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1] found 5 topics possibly matching subscription
2020-10-28 12:22:37.776 DEBUG 27226 --- [-StreamThread-1] o.a.k.s.p.i.InternalTopologyBuilder : Updated nodeToSourceTopics: {KTABLE-SOURCE-0000000020=[KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic], KSTREAM-SOURCE-0000000000=[WordCounts], KSTREAM-SOURCE-0000000002=[WordsForNumbers], KTABLE-SOURCE-0000000013=[KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic], GroupName-repartition-source=[GroupName-repartition]}
2020-10-28 12:22:37.782 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Sending JoinGroup (JoinGroupRequestData(groupId='demo-application', sessionTimeoutMs=10000, rebalanceTimeoutMs=300000, memberId='', groupInstanceId=null, protocolType='consumer', protocols=[JoinGroupRequestProtocol(name='stream', metadata=[0, 1, 0, 0, 0, 5, 0, 10, 87, 111, 114, 100, 67, 111, 117, 110, 116, 115, 0, 70, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 75, 84, 65, 66, 76, 69, 45, 70, 75, 45, 74, 79, 73, 78, 45, 83, 85, 66, 83, 67, 82, 73, 80, 84, 73, 79, 78, 45, 82, 69, 83, 80, 79, 78, 83, 69, 45, 48, 48, 48, 48, 48, 48, 48, 48, 49, 56, 45, 116, 111, 112, 105, 99, 0, 15, 87, 111, 114, 100, 115, 70, 111, 114, 78, 117, 109, 98, 101, 114, 115, 0, 38, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 71, 114, 111, 117, 112, 78, 97, 109, 101, 45, 114, 101, 112, 97, 114, 116, 105, 116, 105, 111, 110, 0, 74, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 75, 84, 65, 66, 76, 69, 45, 70, 75, 45, 74, 79, 73, 78, 45, 83, 85, 66, 83, 67, 82, 73, 80, 84, 73, 79, 78, 45, 82, 69, 71, 73, 83, 84, 82, 65, 84, 73, 79, 78, 45, 48, 48, 48, 48, 48, 48, 48, 48, 49, 48, 45, 116, 111, 112, 105, 99, 0, 0, 0, 36, 0, 0, 0, 6, 0, 0, 0, 6, -127, 6, 11, -36, -56, -52, 67, 80, -123, -8, -46, 56, 38, 126, 38, 78, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0])])) to coordinator localhost:50630 (id: 2147483647 rack: null)
2020-10-28 12:22:37.783 DEBUG 27226 --- [-StreamThread-1] o.apache.kafka.common.network.Selector : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Created socket with SO_RCVBUF = 342972, SO_SNDBUF = 146988, SO_TIMEOUT = 0 to node 2147483647
2020-10-28 12:22:37.783 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Completed connection to node 2147483647. Fetching API versions.
2020-10-28 12:22:37.783 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Initiating API versions fetch from node 2147483647.
2020-10-28 12:22:37.784 DEBUG 27226 --- [XT)-PLAINTEXT-1] kafka.request.logger : Completed request:RequestHeader(apiKey=API_VERSIONS, apiVersion=3, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=8) -- {client_software_name=apache-kafka-java,client_software_version=2.5.1,_tagged_fields={}},response:{error_code=0,api_keys=[{api_key=0,min_version=0,max_version=8,_tagged_fields={}},{api_key=1,min_version=0,max_version=11,_tagged_fields={}},{api_key=2,min_version=0,max_version=5,_tagged_fields={}},{api_key=3,min_version=0,max_version=9,_tagged_fields={}},{api_key=4,min_version=0,max_version=4,_tagged_fields={}},{api_key=5,min_version=0,max_version=2,_tagged_fields={}},{api_key=6,min_version=0,max_version=6,_tagged_fields={}},{api_key=7,min_version=0,max_version=3,_tagged_fields={}},{api_key=8,min_version=0,max_version=8,_tagged_fields={}},{api_key=9,min_version=0,max_version=7,_tagged_fields={}},{api_key=10,min_version=0,max_version=3,_tagged_fields={}},{api_key=11,min_version=0,max_version=7,_tagged_fields={}},{api_key=12,min_version=0,max_version=4,_tagged_fields={}},{api_key=13,min_version=0,max_version=4,_tagged_fields={}},{api_key=14,min_version=0,max_version=5,_tagged_fields={}},{api_key=15,min_version=0,max_version=5,_tagged_fields={}},{api_key=16,min_version=0,max_version=3,_tagged_fields={}},{api_key=17,min_version=0,max_version=1,_tagged_fields={}},{api_key=18,min_version=0,max_version=3,_tagged_fields={}},{api_key=19,min_version=0,max_version=5,_tagged_fields={}},{api_key=20,min_version=0,max_version=4,_tagged_fields={}},{api_key=21,min_version=0,max_version=1,_tagged_fields={}},{api_key=22,min_version=0,max_version=3,_tagged_fields={}},{api_key=23,min_version=0,max_version=3,_tagged_fields={}},{api_key=24,min_version=0,max_version=1,_tagged_fields={}},{api_key=25,min_version=0,max_version=1,_tagged_fields={}},{api_key=26,min_version=0,max_version=1,_tagged_fields={}},{api_key=27,min_version=0,max_version=0,_tagged_fields={}},{api_key=28,min_version=0,max_version=3,_tagged_fields={}},{api_key=29,min_version=0,max_version=2,_tagged_fields={}},{api_key=30,min_version=0,max_version=2,_tagged_fields={}},{api_key=31,min_version=0,max_version=2,_tagged_fields={}},{api_key=32,min_version=0,max_version=2,_tagged_fields={}},{api_key=33,min_version=0,max_version=1,_tagged_fields={}},{api_key=34,min_version=0,max_version=1,_tagged_fields={}},{api_key=35,min_version=0,max_version=1,_tagged_fields={}},{api_key=36,min_version=0,max_version=2,_tagged_fields={}},{api_key=37,min_version=0,max_version=2,_tagged_fields={}},{api_key=38,min_version=0,max_version=2,_tagged_fields={}},{api_key=39,min_version=0,max_version=2,_tagged_fields={}},{api_key=40,min_version=0,max_version=2,_tagged_fields={}},{api_key=41,min_version=0,max_version=2,_tagged_fields={}},{api_key=42,min_version=0,max_version=2,_tagged_fields={}},{api_key=43,min_version=0,max_version=2,_tagged_fields={}},{api_key=44,min_version=0,max_version=1,_tagged_fields={}},{api_key=45,min_version=0,max_version=0,_tagged_fields={}},{api_key=46,min_version=0,max_version=0,_tagged_fields={}},{api_key=47,min_version=0,max_version=0,_tagged_fields={}}],throttle_time_ms=0,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50638-2;totalTime:0.661,requestQueueTime:0.107,localTime:0.356,remoteTime:0.0,throttleTime:0.329,responseQueueTime:0.079,sendTime:0.117,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=unknown, softwareVersion=unknown)
2020-10-28 12:22:37.785 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Recorded API versions for node 2147483647: (Produce(0): 0 to 8 [usable: 8], Fetch(1): 0 to 11 [usable: 11], ListOffsets(2): 0 to 5 [usable: 5], Metadata(3): 0 to 9 [usable: 9], LeaderAndIsr(4): 0 to 4 [usable: 4], StopReplica(5): 0 to 2 [usable: 2], UpdateMetadata(6): 0 to 6 [usable: 6], ControlledShutdown(7): 0 to 3 [usable: 3], OffsetCommit(8): 0 to 8 [usable: 8], OffsetFetch(9): 0 to 7 [usable: 7], FindCoordinator(10): 0 to 3 [usable: 3], JoinGroup(11): 0 to 7 [usable: 7], Heartbeat(12): 0 to 4 [usable: 4], LeaveGroup(13): 0 to 4 [usable: 4], SyncGroup(14): 0 to 5 [usable: 5], DescribeGroups(15): 0 to 5 [usable: 5], ListGroups(16): 0 to 3 [usable: 3], SaslHandshake(17): 0 to 1 [usable: 1], ApiVersions(18): 0 to 3 [usable: 3], CreateTopics(19): 0 to 5 [usable: 5], DeleteTopics(20): 0 to 4 [usable: 4], DeleteRecords(21): 0 to 1 [usable: 1], InitProducerId(22): 0 to 3 [usable: 3], OffsetForLeaderEpoch(23): 0 to 3 [usable: 3], AddPartitionsToTxn(24): 0 to 1 [usable: 1], AddOffsetsToTxn(25): 0 to 1 [usable: 1], EndTxn(26): 0 to 1 [usable: 1], WriteTxnMarkers(27): 0 [usable: 0], TxnOffsetCommit(28): 0 to 3 [usable: 3], DescribeAcls(29): 0 to 2 [usable: 2], CreateAcls(30): 0 to 2 [usable: 2], DeleteAcls(31): 0 to 2 [usable: 2], DescribeConfigs(32): 0 to 2 [usable: 2], AlterConfigs(33): 0 to 1 [usable: 1], AlterReplicaLogDirs(34): 0 to 1 [usable: 1], DescribeLogDirs(35): 0 to 1 [usable: 1], SaslAuthenticate(36): 0 to 2 [usable: 2], CreatePartitions(37): 0 to 2 [usable: 2], CreateDelegationToken(38): 0 to 2 [usable: 2], RenewDelegationToken(39): 0 to 2 [usable: 2], ExpireDelegationToken(40): 0 to 2 [usable: 2], DescribeDelegationToken(41): 0 to 2 [usable: 2], DeleteGroups(42): 0 to 2 [usable: 2], ElectLeaders(43): 0 to 2 [usable: 2], IncrementalAlterConfigs(44): 0 to 1 [usable: 1], AlterPartitionReassignments(45): 0 [usable: 0], ListPartitionReassignments(46): 0 [usable: 0], OffsetDelete(47): 0 [usable: 0])
2020-10-28 12:22:37.794 DEBUG 27226 --- [quest-handler-3] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Dynamic member with unknown member id joins group demo-application in Empty state. Created a new member id demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006 and request the member to rejoin with this id.
2020-10-28 12:22:37.798 DEBUG 27226 --- [XT)-PLAINTEXT-1] kafka.request.logger : Completed request:RequestHeader(apiKey=JOIN_GROUP, apiVersion=7, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=7) -- {group_id=demo-application,session_timeout_ms=10000,rebalance_timeout_ms=300000,member_id=,group_instance_id=null,protocol_type=consumer,protocols=[{name=stream,metadata=java.nio.HeapByteBuffer[pos=0 lim=267 cap=267],_tagged_fields={}}],_tagged_fields={}},response:{throttle_time_ms=0,error_code=79,generation_id=-1,protocol_type=null,protocol_name=null,leader=,member_id=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006,members=[],_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50638-2;totalTime:12.022,requestQueueTime:0.134,localTime:11.638,remoteTime:0.0,throttleTime:0.872,responseQueueTime:0.094,sendTime:0.155,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=apache-kafka-java, softwareVersion=2.5.1)
2020-10-28 12:22:37.798 INFO 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Join group failed with org.apache.kafka.common.errors.MemberIdRequiredException: The group member needs to have a valid member id before actually entering a consumer group
2020-10-28 12:22:37.798 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Disabling heartbeat thread
2020-10-28 12:22:37.798 INFO 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] (Re-)joining group
2020-10-28 12:22:37.798 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.ConsumerCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Joining group with current subscription: [WordCounts, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic, WordsForNumbers, demo-application-GroupName-repartition, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic]
2020-10-28 12:22:37.798 DEBUG 27226 --- [-StreamThread-1] o.a.k.s.p.i.InternalTopologyBuilder : Found pattern subscribed source topics, falling back to pattern subscription for the main consumer.
2020-10-28 12:22:37.799 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Sending JoinGroup (JoinGroupRequestData(groupId='demo-application', sessionTimeoutMs=10000, rebalanceTimeoutMs=300000, memberId='demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006', groupInstanceId=null, protocolType='consumer', protocols=[JoinGroupRequestProtocol(name='stream', metadata=[0, 1, 0, 0, 0, 5, 0, 10, 87, 111, 114, 100, 67, 111, 117, 110, 116, 115, 0, 70, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 75, 84, 65, 66, 76, 69, 45, 70, 75, 45, 74, 79, 73, 78, 45, 83, 85, 66, 83, 67, 82, 73, 80, 84, 73, 79, 78, 45, 82, 69, 83, 80, 79, 78, 83, 69, 45, 48, 48, 48, 48, 48, 48, 48, 48, 49, 56, 45, 116, 111, 112, 105, 99, 0, 15, 87, 111, 114, 100, 115, 70, 111, 114, 78, 117, 109, 98, 101, 114, 115, 0, 38, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 71, 114, 111, 117, 112, 78, 97, 109, 101, 45, 114, 101, 112, 97, 114, 116, 105, 116, 105, 111, 110, 0, 74, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 75, 84, 65, 66, 76, 69, 45, 70, 75, 45, 74, 79, 73, 78, 45, 83, 85, 66, 83, 67, 82, 73, 80, 84, 73, 79, 78, 45, 82, 69, 71, 73, 83, 84, 82, 65, 84, 73, 79, 78, 45, 48, 48, 48, 48, 48, 48, 48, 48, 49, 48, 45, 116, 111, 112, 105, 99, 0, 0, 0, 36, 0, 0, 0, 6, 0, 0, 0, 6, -127, 6, 11, -36, -56, -52, 67, 80, -123, -8, -46, 56, 38, 126, 38, 78, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0])])) to coordinator localhost:50630 (id: 2147483647 rack: null)
2020-10-28 12:22:37.802 DEBUG 27226 --- [quest-handler-6] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Dynamic Member with specific member id demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006 joins group demo-application in Empty state. Adding to the group now.
2020-10-28 12:22:37.804 DEBUG 27226 --- [quest-handler-6] kafka.server.DelayedOperationPurgatory : Request key MemberKey(demo-application,demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006) unblocked 1 Heartbeat operations
2020-10-28 12:22:37.805 INFO 27226 --- [quest-handler-6] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Preparing to rebalance group demo-application in state PreparingRebalance with old generation 0 (__consumer_offsets-2) (reason: Adding new member demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006 with group instance id None)
2020-10-28 12:22:37.806 DEBUG 27226 --- [quest-handler-6] kafka.server.DelayedOperationPurgatory : Request key GroupKey(demo-application) unblocked 0 Rebalance operations
2020-10-28 12:22:37.811 INFO 27226 --- [cutor-Rebalance] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Stabilized group demo-application generation 1 (__consumer_offsets-2)
2020-10-28 12:22:37.813 DEBUG 27226 --- [cutor-Rebalance] kafka.server.DelayedOperationPurgatory : Request key MemberKey(demo-application,demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006) unblocked 1 Heartbeat operations
2020-10-28 12:22:37.814 DEBUG 27226 --- [XT)-PLAINTEXT-1] kafka.request.logger : Completed request:RequestHeader(apiKey=JOIN_GROUP, apiVersion=7, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=9) -- {group_id=demo-application,session_timeout_ms=10000,rebalance_timeout_ms=300000,member_id=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006,group_instance_id=null,protocol_type=consumer,protocols=[{name=stream,metadata=java.nio.HeapByteBuffer[pos=0 lim=267 cap=267],_tagged_fields={}}],_tagged_fields={}},response:{throttle_time_ms=0,error_code=0,generation_id=1,protocol_type=consumer,protocol_name=stream,leader=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006,member_id=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006,members=[{member_id=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006,group_instance_id=null,metadata=java.nio.HeapByteBuffer[pos=0 lim=267 cap=267],_tagged_fields={}}],_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50638-2;totalTime:14.321,requestQueueTime:0.101,localTime:6.806,remoteTime:6.396,throttleTime:0.377,responseQueueTime:0.25,sendTime:0.389,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=apache-kafka-java, softwareVersion=2.5.1)
2020-10-28 12:22:37.814 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Received successful JoinGroup response: JoinGroupResponseData(throttleTimeMs=0, errorCode=0, generationId=1, protocolType='consumer', protocolName='stream', leader='demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006', memberId='demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006', members=[JoinGroupResponseMember(memberId='demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006', groupInstanceId=null, metadata=[0, 1, 0, 0, 0, 5, 0, 10, 87, 111, 114, 100, 67, 111, 117, 110, 116, 115, 0, 70, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 75, 84, 65, 66, 76, 69, 45, 70, 75, 45, 74, 79, 73, 78, 45, 83, 85, 66, 83, 67, 82, 73, 80, 84, 73, 79, 78, 45, 82, 69, 83, 80, 79, 78, 83, 69, 45, 48, 48, 48, 48, 48, 48, 48, 48, 49, 56, 45, 116, 111, 112, 105, 99, 0, 15, 87, 111, 114, 100, 115, 70, 111, 114, 78, 117, 109, 98, 101, 114, 115, 0, 38, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 71, 114, 111, 117, 112, 78, 97, 109, 101, 45, 114, 101, 112, 97, 114, 116, 105, 116, 105, 111, 110, 0, 74, 100, 101, 109, 111, 45, 97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 45, 75, 84, 65, 66, 76, 69, 45, 70, 75, 45, 74, 79, 73, 78, 45, 83, 85, 66, 83, 67, 82, 73, 80, 84, 73, 79, 78, 45, 82, 69, 71, 73, 83, 84, 82, 65, 84, 73, 79, 78, 45, 48, 48, 48, 48, 48, 48, 48, 48, 49, 48, 45, 116, 111, 112, 105, 99, 0, 0, 0, 36, 0, 0, 0, 6, 0, 0, 0, 6, -127, 6, 11, -36, -56, -52, 67, 80, -123, -8, -46, 56, 38, 126, 38, 78, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0])])
2020-10-28 12:22:37.873 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Sending metadata request MetadataRequestData(topics=[MetadataRequestTopic(name='WordCounts'), MetadataRequestTopic(name='demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic'), MetadataRequestTopic(name='WordsForNumbers'), MetadataRequestTopic(name='demo-application-GroupName-repartition'), MetadataRequestTopic(name='demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic')], allowAutoTopicCreation=false, includeClusterAuthorizedOperations=false, includeTopicAuthorizedOperations=false) to node localhost:50630 (id: 0 rack: null)
2020-10-28 12:22:37.876 WARN 27226 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Error while fetching metadata with correlation id 10 : {demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic=UNKNOWN_TOPIC_OR_PARTITION, demo-application-GroupName-repartition=UNKNOWN_TOPIC_OR_PARTITION, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic=UNKNOWN_TOPIC_OR_PARTITION}
2020-10-28 12:22:37.875 DEBUG 27226 --- [XT)-PLAINTEXT-0] kafka.request.logger : Completed request:RequestHeader(apiKey=METADATA, apiVersion=9, clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, correlationId=10) -- {topics=[{name=WordCounts,_tagged_fields={}},{name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic,_tagged_fields={}},{name=WordsForNumbers,_tagged_fields={}},{name=demo-application-GroupName-repartition,_tagged_fields={}},{name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic,_tagged_fields={}}],allow_auto_topic_creation=false,include_cluster_authorized_operations=false,include_topic_authorized_operations=false,_tagged_fields={}},response:{throttle_time_ms=0,brokers=[{node_id=0,host=localhost,port=50630,rack=null,_tagged_fields={}}],cluster_id=N7jaHn0uT--Z2F-IG9Te3g,controller_id=0,topics=[{error_code=0,name=WordsForNumbers,is_internal=false,partitions=[{error_code=0,partition_index=0,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}},{error_code=0,partition_index=1,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}}],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=0,name=WordCounts,is_internal=false,partitions=[{error_code=0,partition_index=0,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}},{error_code=0,partition_index=1,leader_id=0,leader_epoch=0,replica_nodes=[0],isr_nodes=[0],offline_replicas=[],_tagged_fields={}}],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=3,name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic,is_internal=false,partitions=[],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=3,name=demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic,is_internal=false,partitions=[],topic_authorized_operations=-2147483648,_tagged_fields={}},{error_code=3,name=demo-application-GroupName-repartition,is_internal=false,partitions=[],topic_authorized_operations=-2147483648,_tagged_fields={}}],cluster_authorized_operations=-2147483648,_tagged_fields={}} from connection 127.0.0.1:50630-127.0.0.1:50637-2;totalTime:1.644,requestQueueTime:0.172,localTime:1.118,remoteTime:0.0,throttleTime:0.356,responseQueueTime:0.094,sendTime:0.259,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS,listener:PLAINTEXT,clientInformation:ClientInformation(softwareName=apache-kafka-java, softwareVersion=2.5.1)
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordsForNumbers-0 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordsForNumbers-1 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordCounts-0 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updating last seen epoch for partition WordCounts-1 from 0 to epoch 0 from new metadata
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Requesting metadata update for topic demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic due to error UNKNOWN_TOPIC_OR_PARTITION
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Requesting metadata update for topic demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic due to error UNKNOWN_TOPIC_OR_PARTITION
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Requesting metadata update for topic demo-application-GroupName-repartition due to error UNKNOWN_TOPIC_OR_PARTITION
2020-10-28 12:22:37.876 DEBUG 27226 --- [-StreamThread-1] org.apache.kafka.clients.Metadata : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Updated cluster metadata updateVersion 4 to MetadataCache{clusterId='N7jaHn0uT--Z2F-IG9Te3g', nodes={0=localhost:50630 (id: 0 rack: null)}, partitions=[PartitionMetadata(, error=NONE, partition=WordCounts-1, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=), PartitionMetadata(, error=NONE, partition=WordCounts-0, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=), PartitionMetadata(, error=NONE, partition=WordsForNumbers-0, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=), PartitionMetadata(, error=NONE, partition=WordsForNumbers-1, leader=Optional[0], leaderEpoch=Optional[0], replicas=0, isr=0, offlineReplicas=)], controller=localhost:50630 (id: 0 rack: null)}
2020-10-28 12:22:37.877 DEBUG 27226 --- [-StreamThread-1] o.a.k.c.c.internals.ConsumerCoordinator : [Consumer clientId=demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer, groupId=demo-application] Performing assignment using strategy stream with subscriptions {demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006=org.apache.kafka.clients.consumer.ConsumerPartitionAssignor$Subscription@72fef550}
2020-10-28 12:22:37.878 DEBUG 27226 --- [-StreamThread-1] o.a.k.s.p.i.StreamsPartitionAssignor : stream-thread [demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer] Current minimum supported version remains at 6, last seen supported version was 6
2020-10-28 12:22:37.879 DEBUG 27226 --- [-StreamThread-1] o.a.k.s.p.i.StreamsPartitionAssignor : stream-thread [demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer] Constructed client metadata {81060bdc-c8cc-4350-85f8-d238267e264e=ClientMetadata{hostInfo=null, consumers=[demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006], state=[activeTasks: ([]) standbyTasks: ([]) assignedTasks: ([]) prevActiveTasks: ([]) prevStandbyTasks: ([]) prevAssignedTasks: ([]) prevOwnedPartitionsByConsumerId: ([]) capacity: 1]}} from the member subscriptions.
2020-10-28 12:22:38.093 DEBUG 27226 --- [ Test worker] c.DefaultCacheAwareContextLoaderDelegate : Retrieved ApplicationContext [711655536] from cache with key [[MergedContextConfiguration@6f619745 testClass = StreamsConfigurationTest, locations = '{}', classes = '{class com.github.ajablonski.StreamsConfiguration, class com.github.ajablonski.StreamsConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{spring.application.name=demo-application, spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}, org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true}', contextCustomizers = set[org.springframework.kafka.test.context.EmbeddedKafkaContextCustomizer@286523bc, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@53950fea, [ImportsContextCustomizer@7e41aeb8 key = [@org.apiguardian.api.API(consumers={"*"}, since="5.0", status=STABLE), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.kafka.test.condition.EmbeddedKafkaCondition.class}), @org.springframework.boot.autoconfigure.EnableAutoConfiguration(exclude={}, excludeName={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationPackages$Registrar.class}), @org.springframework.test.context.BootstrapWith(value=org.springframework.boot.test.context.SpringBootTestContextBootstrapper.class), @org.springframework.kafka.test.context.EmbeddedKafka(partitions=2, bootstrapServersProperty="", brokerPropertiesLocation="", zookeeperPort=0, topics={"WordCounts", "WordsForNumbers", "OutputTopic"}, controlledShutdown=false, count=1, brokerProperties={}, zkConnectionTimeout=6000, ports={0}, value=1, zkSessionTimeout=6000), @org.junit.jupiter.api.extension.ExtendWith(value={org.springframework.test.context.junit.jupiter.SpringExtension.class}), @org.springframework.boot.test.context.SpringBootTest(args={}, webEnvironment=MOCK, value={}, properties={"spring.application.name=demo-application", "spring.kafka.bootstrap-servers=${spring.embedded.kafka.brokers}"}, classes={com.github.ajablonski.StreamsConfiguration.class}), @org.springframework.boot.autoconfigure.AutoConfigurationPackage(basePackages={}, basePackageClasses={}), @org.springframework.context.annotation.Import(value={org.springframework.boot.autoconfigure.AutoConfigurationImportSelector.class})]], org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@412b5795, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@52281bb6, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.web.client.TestRestTemplateContextCustomizer@7b0749e2, org.springframework.boot.test.context.SpringBootTestArgs@1], contextLoader = 'org.springframework.boot.test.context.SpringBootContextLoader', parent = [null]]]
2020-10-28 12:22:38.093 DEBUG 27226 --- [ Test worker] org.springframework.test.context.cache : Spring test ApplicationContext cache statistics: [DefaultContextCache@1bbf537b size = 1, maxSize = 32, parentContextCount = 0, hitCount = 4, missCount = 1]
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
2020-10-28 12:22:41.402 INFO 27226 --- [er-event-thread] kafka.controller.KafkaController : [Controller id=0] Processing automatic preferred replica leader election
2020-10-28 12:22:41.405 DEBUG 27226 --- [er-event-thread] kafka.controller.KafkaController : [Controller id=0] Topics not in preferred replica for broker 0 Map()
2020-10-28 12:22:41.406 DEBUG 27226 --- [er-event-thread] kafka.utils.KafkaScheduler : Scheduling task auto-leader-rebalance-task with initial delay 300000 ms and period -1000 ms.
State is REBALANCING
2020-10-28 12:22:43.101 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:43.102 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:43.102 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:43.102 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 1ms
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
2020-10-28 12:22:47.815 INFO 27226 --- [cutor-Heartbeat] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Member demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006 in group demo-application has failed, removing it from the group
2020-10-28 12:22:47.816 INFO 27226 --- [cutor-Heartbeat] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Preparing to rebalance group demo-application in state PreparingRebalance with old generation 1 (__consumer_offsets-2) (reason: removing member demo-application-81060bdc-c8cc-4350-85f8-d238267e264e-StreamThread-1-consumer-976853d9-06ad-4515-abf3-2a7398c12006 on heartbeat expiration)
2020-10-28 12:22:47.816 INFO 27226 --- [cutor-Heartbeat] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Group demo-application with generation 2 is now empty (__consumer_offsets-2)
2020-10-28 12:22:47.872 DEBUG 27226 --- [cutor-Heartbeat] kafka.cluster.Partition : [Partition __consumer_offsets-2 broker=0] High watermark updated from (offset=0 segment=[0:0]) to (offset=1 segment=[0:120])
2020-10-28 12:22:47.872 DEBUG 27226 --- [cutor-Heartbeat] kafka.server.DelayedOperationPurgatory : Request key TopicPartitionOperationKey(__consumer_offsets,2) unblocked 0 Fetch operations
2020-10-28 12:22:47.873 DEBUG 27226 --- [cutor-Heartbeat] kafka.server.DelayedOperationPurgatory : Request key TopicPartitionOperationKey(__consumer_offsets,2) unblocked 0 Produce operations
2020-10-28 12:22:47.873 DEBUG 27226 --- [cutor-Heartbeat] kafka.server.DelayedOperationPurgatory : Request key TopicPartitionOperationKey(__consumer_offsets,2) unblocked 0 DeleteRecords operations
2020-10-28 12:22:47.874 DEBUG 27226 --- [cutor-Heartbeat] kafka.server.ReplicaManager : [ReplicaManager broker=0] Produce to local log in 40 ms
State is REBALANCING
2020-10-28 12:22:48.439 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:48.439 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:48.439 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:48.439 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
State is REBALANCING
2020-10-28 12:22:50.838 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905770835 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:22:50.841 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905770835 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:22:50.842 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905770835 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:22:50.842 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905770835 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:22:50.842 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905770835 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
State is REBALANCING
State is REBALANCING
State is REBALANCING
2020-10-28 12:22:53.774 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:53.775 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:53.775 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:53.775 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
2020-10-28 12:22:59.110 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:22:59.110 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:59.110 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:22:59.111 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
State is REBALANCING
2020-10-28 12:23:04.448 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:04.448 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:04.448 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:04.449 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
2020-10-28 12:23:05.814 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking for dirty logs to flush...
2020-10-28 12:23:05.814 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Beginning log cleanup...
2020-10-28 12:23:05.815 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:23:05.815 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on WordCounts flush interval 9223372036854775807 last flushed 1603905756745 time since last flush: 29070
2020-10-28 12:23:05.815 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on WordCounts flush interval 9223372036854775807 last flushed 1603905756733 time since last flush: 29082
2020-10-28 12:23:05.815 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on __consumer_offsets flush interval 9223372036854775807 last flushed 1603905757713 time since last flush: 28102
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on OutputTopic flush interval 9223372036854775807 last flushed 1603905756740 time since last flush: 29076
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on OutputTopic flush interval 9223372036854775807 last flushed 1603905756726 time since last flush: 29090
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on WordsForNumbers flush interval 9223372036854775807 last flushed 1603905756649 time since last flush: 29167
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on __consumer_offsets flush interval 9223372036854775807 last flushed 1603905757753 time since last flush: 28063
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on WordsForNumbers flush interval 9223372036854775807 last flushed 1603905756702 time since last flush: 29114
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on __consumer_offsets flush interval 9223372036854775807 last flushed 1603905757722 time since last flush: 28094
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on __consumer_offsets flush interval 9223372036854775807 last flushed 1603905757733 time since last flush: 28083
2020-10-28 12:23:05.816 DEBUG 27226 --- [fka-scheduler-4] kafka.log.LogManager : Checking if flush is needed on __consumer_offsets flush interval 9223372036854775807 last flushed 1603905757744 time since last flush: 28072
2020-10-28 12:23:05.817 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Garbage collecting 'WordCounts-1'
2020-10-28 12:23:05.817 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Garbage collecting 'WordCounts-0'
2020-10-28 12:23:05.817 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Garbage collecting 'OutputTopic-1'
2020-10-28 12:23:05.817 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Garbage collecting 'OutputTopic-0'
2020-10-28 12:23:05.817 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Garbage collecting 'WordsForNumbers-0'
2020-10-28 12:23:05.817 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Garbage collecting 'WordsForNumbers-1'
2020-10-28 12:23:05.819 DEBUG 27226 --- [fka-scheduler-6] kafka.log.LogManager : Log cleanup completed. 0 files deleted in 0 seconds
2020-10-28 12:23:05.846 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905785846 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:05.846 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905785846 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:05.846 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905785846 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:05.847 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905785846 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:05.847 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905785846 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
State is REBALANCING
2020-10-28 12:23:06.817 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:07.819 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:08.821 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:09.785 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:09.785 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:09.785 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:09.785 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:23:09.827 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:10.827 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:11.829 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:12.833 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:13.839 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:14.842 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:23:15.119 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:15.119 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:15.119 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:15.119 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
2020-10-28 12:23:15.844 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:16.848 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:17.854 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:18.859 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:19.862 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:20.452 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:20.452 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:20.452 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:20.452 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 1ms
2020-10-28 12:23:20.851 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905800851 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:20.852 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905800851 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:20.852 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905800851 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:20.852 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905800851 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:20.852 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905800851 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:20.863 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:21.868 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:22.870 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:23.874 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:24.875 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:25.790 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:25.791 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:25.791 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:25.791 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 1ms
2020-10-28 12:23:25.877 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:26.880 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:27.885 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:28.891 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:29.893 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:30.896 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:23:31.126 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:31.126 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:31.126 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:31.127 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
2020-10-28 12:23:31.901 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:32.903 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:33.904 DEBUG 27226 --- [fka-scheduler-4] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:34.906 DEBUG 27226 --- [fka-scheduler-4] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:35.855 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905815854 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:35.855 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905815854 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:35.856 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905815854 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:35.856 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905815854 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:35.856 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905815854 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:35.909 DEBUG 27226 --- [fka-scheduler-4] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:36.460 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:36.460 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:36.460 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:36.460 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:23:36.912 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:37.914 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:38.918 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:39.923 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:40.928 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:41.795 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:41.795 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:41.795 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:41.795 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:23:41.928 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:42.933 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:43.936 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:44.940 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:45.940 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:46.943 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:23:47.128 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:47.128 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:47.128 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:47.128 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
2020-10-28 12:23:47.947 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:48.951 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:49.956 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:50.861 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905830861 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:50.861 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905830861 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:50.861 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905830861 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:50.862 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905830861 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:50.862 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905830861 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:23:50.959 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:51.961 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:52.461 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:52.461 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:52.461 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:52.461 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:23:52.962 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:53.963 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:54.968 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:55.973 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:56.974 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:57.795 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:23:57.795 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:57.795 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:23:57.796 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:23:57.977 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:58.978 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:23:59.978 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:00.983 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:01.985 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:02.989 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:24:03.129 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:03.129 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:03.129 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:03.129 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
2020-10-28 12:24:03.991 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:04.996 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:05.864 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905845863 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:05.865 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905845863 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:05.865 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905845863 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:05.865 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905845863 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:05.865 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905845863 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:05.998 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:07.002 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:08.003 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:08.468 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:08.468 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:08.468 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:08.468 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:24:09.008 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:10.008 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:11.009 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:12.013 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:13.018 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:13.802 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:13.802 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:13.802 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:13.802 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:24:14.020 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:15.020 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:16.024 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:17.025 DEBUG 27226 --- [fka-scheduler-4] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:18.026 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:19.028 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:24:19.139 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:19.139 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:19.139 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:19.139 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
2020-10-28 12:24:20.028 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:20.868 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905860868 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:20.868 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905860868 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:20.868 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905860868 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:20.868 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905860868 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:20.869 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905860868 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:21.030 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:22.035 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:23.039 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:24.041 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:24.473 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:24.473 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:24.473 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:24.473 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:24:25.044 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:26.048 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:27.051 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:28.055 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:29.059 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:29.806 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:29.806 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:29.807 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:29.807 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 1ms
2020-10-28 12:24:30.060 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:31.063 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:32.068 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:33.071 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:34.076 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:35.077 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:24:35.143 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:35.143 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:35.143 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:35.144 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 1ms
State is REBALANCING
2020-10-28 12:24:35.871 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905875869 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:35.872 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905875869 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:35.872 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905875869 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:35.872 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905875869 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:35.872 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905875869 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:36.082 DEBUG 27226 --- [fka-scheduler-3] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:37.087 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:38.092 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:39.094 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:40.100 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:40.477 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:40.478 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:40.478 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:40.478 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:24:41.105 DEBUG 27226 --- [fka-scheduler-0] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:42.109 DEBUG 27226 --- [fka-scheduler-4] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:43.113 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:44.119 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:45.122 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:45.813 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:45.813 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:45.813 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:45.813 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:24:46.127 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:47.127 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:48.131 DEBUG 27226 --- [fka-scheduler-7] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:49.137 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:50.139 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:50.873 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-0. Last clean offset=None now=1603905890873 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:50.873 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-3. Last clean offset=None now=1603905890873 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:50.874 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-4. Last clean offset=None now=1603905890873 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:50.874 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-1. Last clean offset=None now=1603905890873 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:50.874 DEBUG 27226 --- [leaner-thread-0] kafka.log.LogCleanerManager$ : Finding range of cleanable offsets for log=__consumer_offsets-2. Last clean offset=None now=1603905890873 => firstDirtyOffset=0 firstUncleanableOffset=0 activeSegment.baseOffset=0
2020-10-28 12:24:51.144 DEBUG 27226 --- [fka-scheduler-8] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
2020-10-28 12:24:51.152 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:51.152 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:51.152 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:51.152 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
State is REBALANCING
2020-10-28 12:24:52.146 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:53.151 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:54.153 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:55.154 DEBUG 27226 --- [fka-scheduler-2] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:56.158 DEBUG 27226 --- [fka-scheduler-9] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:56.489 DEBUG 27226 --- [0 cport:50628):] o.a.zookeeper.server.SessionTrackerImpl : Checking session 0x1001183e8060000
2020-10-28 12:24:56.489 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : Processing request:: sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:56.489 DEBUG 27226 --- [ SyncThread:0] o.a.z.server.FinalRequestProcessor : sessionid:0x1001183e8060000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2020-10-28 12:24:56.489 DEBUG 27226 --- [27.0.0.1:50628)] org.apache.zookeeper.ClientCnxn : Got ping response for sessionid: 0x1001183e8060000 after 0ms
2020-10-28 12:24:57.160 DEBUG 27226 --- [fka-scheduler-1] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:58.164 DEBUG 27226 --- [fka-scheduler-5] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:24:59.168 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
State is REBALANCING
2020-10-28 12:25:00.169 DEBUG 27226 --- [fka-scheduler-6] kafka.utils.KafkaScheduler : Scheduling task kafka-delete-logs with initial delay 1000 ms and period -1 ms.
>
> We've been able to get the crucial factors that cause this behavior down to
> a particular combination
What do you mean by this -- that you only see this when all four of those
operators
are at play? Or do you see it with any of them.
I guess the first thing to narrow down is whether it's actually rebalancing
or just
restoring within this time (the REBALANCING state is somewhat
misleadingly-named).
If this is a completely new app then it's probably not restoring, but if
this app had
already been running and building up state before hitting this issue then
that's probably
the reason. It's not at all uncommon for restoration to take more than 30
seconds.
If it really is rebalancing this entire time, then you need to look into
the logs to figure
out why. I don't see anything obviously wrong with your particular
application, and even
if there was it should never result in endless rebalances like this. How
many instances
of the application are you running?
2020-10-28 12:11:19.823 INFO 27127 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer, groupId=demo-application] Discovered group coordinator localhost:50343 (id: 2147483647 rack: null)
2020-10-28 12:11:19.825 INFO 27127 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer, groupId=demo-application] (Re-)joining group
2020-10-28 12:11:19.842 WARN 27127 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer, groupId=demo-application] Error while fetching metadata with correlation id 7 : {demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic=UNKNOWN_TOPIC_OR_PARTITION, demo-application-GroupName-repartition=UNKNOWN_TOPIC_OR_PARTITION, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic=UNKNOWN_TOPIC_OR_PARTITION}
2020-10-28 12:11:19.860 INFO 27127 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer, groupId=demo-application] Join group failed with org.apache.kafka.common.errors.MemberIdRequiredException: The group member needs to have a valid member id before actually entering a consumer group
2020-10-28 12:11:19.861 INFO 27127 --- [-StreamThread-1] o.a.k.c.c.internals.AbstractCoordinator : [Consumer clientId=demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer, groupId=demo-application] (Re-)joining group
2020-10-28 12:11:19.873 INFO 27127 --- [quest-handler-3] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Preparing to rebalance group demo-application in state PreparingRebalance with old generation 0 (__consumer_offsets-2) (reason: Adding new member demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer-cabbd9ce-83a7-4691-8599-b2ffe77da282 with group instance id None)
2020-10-28 12:11:19.882 INFO 27127 --- [cutor-Rebalance] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Stabilized group demo-application generation 1 (__consumer_offsets-2)
2020-10-28 12:11:19.947 WARN 27127 --- [-StreamThread-1] org.apache.kafka.clients.NetworkClient : [Consumer clientId=demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer, groupId=demo-application] Error while fetching metadata with correlation id 9 : {demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-RESPONSE-0000000018-topic=UNKNOWN_TOPIC_OR_PARTITION, demo-application-GroupName-repartition=UNKNOWN_TOPIC_OR_PARTITION, demo-application-KTABLE-FK-JOIN-SUBSCRIPTION-REGISTRATION-0000000010-topic=UNKNOWN_TOPIC_OR_PARTITION}
2020-10-28 12:11:23.462 INFO 27127 --- [er-event-thread] kafka.controller.KafkaController : [Controller id=0] Processing automatic preferred replica leader election
2020-10-28 12:11:29.887 INFO 27127 --- [cutor-Heartbeat] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Member demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer-cabbd9ce-83a7-4691-8599-b2ffe77da282 in group demo-application has failed, removing it from the group
2020-10-28 12:11:29.887 INFO 27127 --- [cutor-Heartbeat] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Preparing to rebalance group demo-application in state PreparingRebalance with old generation 1 (__consumer_offsets-2) (reason: removing member demo-application-714a21af-5fe5-4b9c-8450-53033309a406-StreamThread-1-consumer-cabbd9ce-83a7-4691-8599-b2ffe77da282 on heartbeat expiration)
2020-10-28 12:11:29.888 INFO 27127 --- [cutor-Heartbeat] k.coordinator.group.GroupCoordinator : [GroupCoordinator 0]: Group demo-application with generation 2 is now empty (__consumer_offsets-2)
Cheers,
Sophie
On Thu, Oct 15, 2020 at 10:01 PM Alex Jablonski <ajablonski@thoughtworks.com>
wrote:
> Hey there!
>
> My team and I have run across a bit of a jam in our application where,
> given a particular setup, our Kafka Streams application never seems to
> start successfully, instead just getting stuck in the REBALANCING state.
> We've been able to get the crucial factors that cause this behavior down to
> a particular combination of (1) grouping, (2) windowing, (3) aggregating,
> and (4) foreign-key joining, with some of those steps specifying Serdes
> besides the default.
>
> It's probably more useful to see a minimal example, so there's one here
> <https://github.com/ajablonski/streams-issue-demo/blob/master/build.gradle
> >.
> The underlying Kafka Streams version is 2.5.1. The first test should show
> the application eventually transition to running state, but it doesn't
> within the 30 second timeout I've set. Interestingly, getting rid of the
> 'Grouped.with' argument to the 'groupBy' function and the
> 'Materialized.with' in 'aggregate' in the 'StreamsConfiguration' lets the
> application transition to "RUNNING", though without the correct Serdes
> that's not too valuable.
>
> There might be a cleaner way to organize the particular flow in the toy
> example, but is there something fundamentally wrong with the approach laid
> out in that application that would cause Streams to be stuck in
> REBALANCING? I'd appreciate any advice folks could give!
>
> Thanks!
> Alex Jablonski
>
Comments
Post a Comment