kafkaClient.refreshMetadata callback never called

[iamsahil1989]

We are using KafkaClient refreshMetadata/send like below . But some times the callback is not getting called., due to which our consumer remains paused [we are calling async queue callback within] forever.

producerClient.refreshMetadata([producerTopic], function (error, response) {
        producer.send(payloads, function (err, data) {
             // Code here           
           }
       );
    });

I can see that there is a return statement inside KafkaClient.refreshMetadata which might have caused this.
if (operation.retry(err)) { return; }

Can you please suggest what could be done in this situation

[hyperlink]

We're using the retry module and operation.retry is a way to check the operation will be retried so a return is necessary there. Have you turned on debugging to see if there's any helpful logs there?

[iamsahil1989]

This is happening once in a while .. i will enable debug logs today, but with the application logs it is verified that the callback is never called .. it is either refreshMetadata callback or send callback.

[iamsahil1989]

@hyperlink : I am getting below logs in debug mode in loop . Any idea ?

Mon, 30 Oct 2017 23:37:27 GMT kafka-node:KafkaClient clearing test.com:9092 callback queue without error Mon, 30 Oct 2017 23:37:28 GMT kafka-node:KafkaClient kafka-node-client reconnecting to test.com:9092 Mon, 30 Oct 2017 23:37:28 GMT kafka-node:KafkaClient Sending versions request to test.com:9092 Mon, 30 Oct 2017 23:37:28 GMT kafka-node:KafkaClient Received versions response from test.com:9092 Mon, 30 Oct 2017 23:39:17 GMT kafka-node:KafkaClient clearing test.com:9092 callback queue without error Mon, 30 Oct 2017 23:39:18 GMT kafka-node:KafkaClient kafka-node-client reconnecting to test.com:9092 Mon, 30 Oct 2017 23:39:18 GMT kafka-node:KafkaClient Sending versions request to test.com:9092 Mon, 30 Oct 2017 23:39:18 GMT kafka-node:KafkaClient Received versions response from test.com:9092 Mon, 30 Oct 2017 23:39:28 GMT kafka-node:KafkaClient clearing test.com:9092 callback queue without error Mon, 30 Oct 2017 23:39:29 GMT kafka-node:KafkaClient kafka-node-client reconnecting to test.com:9092 Mon, 30 Oct 2017 23:39:29 GMT kafka-node:KafkaClient Sending versions request to test.com:9092 Mon, 30 Oct 2017 23:39:29 GMT kafka-node:KafkaClient Received versions response from test.com:9092 Mon, 30 Oct 2017 23:41:18 GMT kafka-node:KafkaClient clearing test.com:9092 callback queue without error Mon, 30 Oct 2017 23:41:19 GMT kafka-node:KafkaClient kafka-node-client reconnecting to test.com:9092 Mon, 30 Oct 2017 23:41:19 GMT kafka-node:KafkaClient Sending versions request to test.com:9092 Mon, 30 Oct 2017 23:41:19 GMT kafka-node:KafkaClient Received versions response from test.com:9092 Mon, 30 Oct 2017 23:41:29 GMT kafka-node:KafkaClient clearing test.com:9092 callback queue without error Mon, 30 Oct 2017 23:41:30 GMT kafka-node:KafkaClient kafka-node-client reconnecting to test.com:9092 Mon, 30 Oct 2017 23:41:30 GMT kafka-node:KafkaClient Sending versions request to test.com:9092 Mon, 30 Oct 2017 23:41:30 GMT kafka-node:KafkaClient Received versions response from test.com:9092

[hyperlink]

What version of Kafka are you using?

[iamsahil1989]

We are using kafka 0.10.2.1. And the version of kafka-node we are using is 2.2.3

[hyperlink]

Could you checkout the code, setup docker (description in the README) and create sample code that replicates this issue?

[iamsahil1989]

@hyperlink : Thanks. I will try to do so. Can you please confirm, with the kafka-node 2.2.3 is it a good idea to call refresh metadata before producer.send ?

I believe the issue that i talked about arises when:

1. producerClient.refreshMetadata
2. Consumer error #1 calls self.loadMetadataForTopics
3. which then queue callback "this.queueCallback(broker.socket, correlationId, [protocol.decodeMetadataResponse, cb]);"
4. Post which socket connection get's closed , due to which callback queue is cleared and callback is never called.

Can you please help here. I am trying to replicate the situation in the meantime

[hyperlink]

the callback queues are cleared when the socket is closed. There maybe a period of time before node notices that the socket is closed (TCP/IP sockets seems forgiving).

[iamsahil1989]

@hyperlink : So i believe i need to figure out a work around to fix this. Thanks for the response.

I can understand the need to refresh metadata (broker down, rebalancing, etc) , do i need to explicitly call refresh metadata before every send request ? I can see that in case of 'brokerNotAvailable' refresh metadata is called, but are other cases catered as well (like increase in the number of partitions ?)

[hyperlink]

@iamsahil1989 refreshing periodically seems reasonable and would catch the case when the number of partitions has been increased. Calling refresh before every send request seems overkill.

[iamsahil1989]

@hyperlink : Thanks a lot :)