Hi there.
I'm trying to get Kafka Unit integrated with a kafka consumer of the new flavor as described in pom:
I'm able to produce messages but the consumer is somehow not able to consume, although there is nothing in the logs that appear out of the ordinary. I'm able to use a off process kafka server for my unit tests at this time, but it's not ideal.
2016-05-20 11:05:54 DEBUG NetworkClient:619 - Sending metadata request ClientRequest(expectResponse=true, callback=null, request=RequestSend(header={api_key=3,api_version=0,correlation_id=17,client_id=consumer-1}, body={topics=[test-b-topic]}), isInitiatedByNetworkClient, createdTimeMs=1463756754256, sendTimeMs=0) to node 1
2016-05-20 11:05:54 INFO GroupMetadataManager:68 - [Group Metadata Manager on Broker 1]: Finished loading offsets from [__consumer_offsets,45] in 1 milliseconds.
2016-05-20 11:05:54 INFO GroupMetadataManager:68 - [Group Metadata Manager on Broker 1]: Loading offsets and group metadata from [__consumer_offsets,48]
2016-05-20 11:05:54 DEBUG Metadata:172 - Updated cluster metadata version 10 to Cluster(nodes = [Node(1, localhost, 6692)], partitions = [Partition(topic = test-b-topic, partition = 0, leader = 1, replicas = [1,], isr = [1,]])
2016-05-20 11:05:54 DEBUG logger:138 - Completed request:Name: TopicMetadataRequest; Version: 0; CorrelationId: 17; ClientId: consumer-1 from connection 127.0.0.1:6692-127.0.0.1:43094;totalTime:1,requestQueueTime:0,localTime:1,remoteTime:0,responseQueueTime:0,sendTime:0,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:54 DEBUG AbstractCoordinator:465 - Issuing group metadata request to broker 1
2016-05-20 11:05:54 INFO GroupMetadataManager:68 - [Group Metadata Manager on Broker 1]: Finished loading offsets from [__consumer_offsets,48] in 1 milliseconds.
2016-05-20 11:05:54 DEBUG AbstractCoordinator:478 - Group metadata response ClientResponse(receivedTimeMs=1463756754261, disconnected=false, request=ClientRequest(expectResponse=true, callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@76c76263, request=RequestSend(header={api_key=10,api_version=0,correlation_id=18,client_id=consumer-1}, body={group_id=test-group-id}), createdTimeMs=1463756754258, sendTimeMs=1463756754258), responseBody={error_code=0,coordinator={node_id=1,host=localhost,port=6692}})
2016-05-20 11:05:54 DEBUG NetworkClient:487 - Initiating connection to node 2147483646 at localhost:6692.
2016-05-20 11:05:54 DEBUG logger:138 - Completed request:{api_key=10,api_version=0,correlation_id=18,client_id=consumer-1} -- {group_id=test-group-id} from connection 127.0.0.1:6692-127.0.0.1:43094;totalTime:3,requestQueueTime:0,localTime:3,remoteTime:0,responseQueueTime:0,sendTime:0,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:54 DEBUG ConsumerCoordinator:247 - Revoking previously assigned partitions []
2016-05-20 11:05:54 DEBUG Acceptor:52 - Accepted connection from /127.0.0.1 on /127.0.0.1:6692. sendBufferSize [actual|requested]: [102400|102400] recvBufferSize [actual|requested]: [102400|102400]
2016-05-20 11:05:54 DEBUG AbstractCoordinator:309 - (Re-)joining group test-group-id
2016-05-20 11:05:54 DEBUG Processor:52 - Processor 0 listening to new connection from /127.0.0.1:43096
2016-05-20 11:05:54 DEBUG AbstractCoordinator:318 - Issuing request (JOIN_GROUP: {group_id=test-group-id,session_timeout=30000,member_id=,protocol_type=consumer,group_protocols=[{protocol_name=range,protocol_metadata=java.nio.HeapByteBuffer[pos=0 lim=24 cap=24]}]}) to coordinator 2147483646
2016-05-20 11:05:54 DEBUG Metrics:201 - Added sensor with name node-2147483646.bytes-sent
2016-05-20 11:05:54 DEBUG Metrics:201 - Added sensor with name node-2147483646.bytes-received
2016-05-20 11:05:54 DEBUG Metrics:201 - Added sensor with name node-2147483646.latency
2016-05-20 11:05:54 DEBUG NetworkClient:467 - Completed connection to node 2147483646
2016-05-20 11:05:54 INFO GroupCoordinator:68 - [GroupCoordinator 1]: Preparing to restabilize group test-group-id with old generation 0
2016-05-20 11:05:54 INFO GroupCoordinator:68 - [GroupCoordinator 1]: Stabilized group test-group-id generation 1
2016-05-20 11:05:54 DEBUG AbstractCoordinator:336 - Joined group: {error_code=0,generation_id=1,group_protocol=range,leader_id=consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137,member_id=consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137,members=[{member_id=consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137,member_metadata=java.nio.HeapByteBuffer[pos=0 lim=24 cap=24]}]}
2016-05-20 11:05:54 DEBUG logger:138 - Completed request:{api_key=11,api_version=0,correlation_id=19,client_id=consumer-1} -- {group_id=test-group-id,session_timeout=30000,member_id=,protocol_type=consumer,group_protocols=[{protocol_name=range,protocol_metadata=java.nio.HeapByteBuffer[pos=0 lim=24 cap=24]}]} from connection 127.0.0.1:6692-127.0.0.1:43096;totalTime:12,requestQueueTime:0,localTime:12,remoteTime:0,responseQueueTime:0,sendTime:0,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:54 DEBUG ConsumerCoordinator:225 - Performing range assignment for subscriptions {consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137=org.apache.kafka.clients.consumer.internals.PartitionAssignor$Subscription@5d4a76ed}
2016-05-20 11:05:54 DEBUG ConsumerCoordinator:229 - Finished assignment: {consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137=org.apache.kafka.clients.consumer.internals.PartitionAssignor$Assignment@5a354c6d}
2016-05-20 11:05:54 DEBUG AbstractCoordinator:397 - Issuing leader SyncGroup (SYNC_GROUP: {group_id=test-group-id,generation_id=1,member_id=consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137,group_assignment=[{member_id=consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137,member_assignment=java.nio.HeapByteBuffer[pos=0 lim=32 cap=32]}]}) to coordinator 2147483646
2016-05-20 11:05:54 INFO GroupCoordinator:68 - [GroupCoordinator 1]: Assignment received from leader for group test-group-id for generation 1
2016-05-20 11:05:54 DEBUG Log:52 - Flushing log '__consumer_offsets-38 up to offset 1, last flushed: 1463756754150 current time: 1463756754292 unflushed = 1
2016-05-20 11:05:54 DEBUG ReplicaManager:52 - [Replica Manager on Broker 1]: Request key __consumer_offsets-38 unblocked 0 fetch requests.
2016-05-20 11:05:54 DEBUG Partition:52 - Partition [__consumer_offsets,38] on broker 1: High watermark for partition [__consumer_offsets,38] updated to 1 [0 : 260]
2016-05-20 11:05:54 DEBUG ReplicaManager:52 - [Replica Manager on Broker 1]: Request key __consumer_offsets-38 unblocked 0 fetch requests.
2016-05-20 11:05:54 DEBUG ReplicaManager:52 - [Replica Manager on Broker 1]: Request key __consumer_offsets-38 unblocked 0 producer requests.
2016-05-20 11:05:54 DEBUG ReplicaManager:52 - [Replica Manager on Broker 1]: Produce to local log in 17 ms
2016-05-20 11:05:54 DEBUG AbstractCoordinator:423 - Received successful sync group response for group test-group-id: {error_code=0,member_assignment=java.nio.HeapByteBuffer[pos=0 lim=32 cap=32]}
2016-05-20 11:05:54 DEBUG logger:138 - Completed request:{api_key=14,api_version=0,correlation_id=20,client_id=consumer-1} -- {group_id=test-group-id,generation_id=1,member_id=consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137,group_assignment=[{member_id=consumer-1-2ef8ed6a-4ab2-42a8-8c4b-455aaad2c137,member_assignment=java.nio.HeapByteBuffer[pos=0 lim=32 cap=32]}]} from connection 127.0.0.1:6692-127.0.0.1:43096;totalTime:29,requestQueueTime:0,localTime:29,remoteTime:0,responseQueueTime:0,sendTime:0,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:54 DEBUG ConsumerCoordinator:191 - Setting newly assigned partitions [test-b-topic-0]
2016-05-20 11:05:54 DEBUG ConsumerCoordinator:581 - Fetching committed offsets for partitions: [test-b-topic-0]
2016-05-20 11:05:54 DEBUG logger:138 - Completed request:Name: OffsetFetchRequest; Version: 1; CorrelationId: 21; ClientId: consumer-1; GroupId: test-group-id from connection 127.0.0.1:6692-127.0.0.1:43096;totalTime:7,requestQueueTime:2,localTime:5,remoteTime:0,responseQueueTime:0,sendTime:0,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:54 DEBUG ConsumerCoordinator:628 - No committed offset for partition test-b-topic-0
2016-05-20 11:05:54 DEBUG Fetcher:290 - Resetting offset for partition test-b-topic-0 to latest offset.
2016-05-20 11:05:54 DEBUG logger:138 - Completed request:Name: OffsetRequest; Version: 0; CorrelationId: 22; ClientId: consumer-1; ReplicaId: -1 from connection 127.0.0.1:6692-127.0.0.1:43094;totalTime:9,requestQueueTime:1,localTime:8,remoteTime:0,responseQueueTime:0,sendTime:0,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:54 DEBUG Fetcher:483 - Fetched offset 0 for partition test-b-topic-0
2016-05-20 11:05:54 DEBUG Metrics:201 - Added sensor with name FetchThrottleTime-consumer-1
2016-05-20 11:05:54 DEBUG Metrics:201 - Added sensor with name Fetch-consumer-1
2016-05-20 11:05:54 DEBUG logger:138 - Completed request:Name: FetchRequest; Version: 1; CorrelationId: 23; ClientId: consumer-1; ReplicaId: -1; MaxWait: 500 ms; MinBytes: 1 bytes from connection 127.0.0.1:6692-127.0.0.1:43094;totalTime:514,requestQueueTime:2,localTime:4,remoteTime:501,responseQueueTime:0,sendTime:1,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:54 DEBUG Metrics:201 - Added sensor with name topic.test-b-topic.bytes-fetched
2016-05-20 11:05:54 DEBUG Metrics:201 - Added sensor with name topic.test-b-topic.records-fetched
2016-05-20 11:05:55 DEBUG logger:138 - Completed request:Name: FetchRequest; Version: 1; CorrelationId: 24; ClientId: consumer-1; ReplicaId: -1; MaxWait: 500 ms; MinBytes: 1 bytes from connection 127.0.0.1:6692-127.0.0.1:43094;totalTime:501,requestQueueTime:0,localTime:0,remoteTime:500,responseQueueTime:0,sendTime:1,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:55 DEBUG logger:138 - Completed request:Name: FetchRequest; Version: 1; CorrelationId: 25; ClientId: consumer-1; ReplicaId: -1; MaxWait: 500 ms; MinBytes: 1 bytes from connection 127.0.0.1:6692-127.0.0.1:43094;totalTime:501,requestQueueTime:0,localTime:0,remoteTime:500,responseQueueTime:0,sendTime:0,securityProtocol:PLAINTEXT,principal:User:ANONYMOUS
2016-05-20 11:05:56 DEBUG FinalRequestProcessor:88 - Processing request:: sessionid:0x154ceb36b800000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2016-05-20 11:05:56 DEBUG FinalRequestProcessor:160 - sessionid:0x154ceb36b800000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2016-05-20 11:05:56 DEBUG ClientCnxn:717 - Got ping response for sessionid: 0x154ceb36b800000 after 0ms