query_watermark_offsets() fails on first attempt

[edenhill]

Description

Calling query_watermark_offsets() on a newly created consumer that has retrieved cluster metadata but no topic metadata will fail for the first call:

Reported in confluentinc/confluent-kafka-python#196

How to reproduce

%7|1502285441.278|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62954/4: ===== Received metadata: connected =====
%7|1502285441.278|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62954/4: ClusterId: rxqnDq58T5K4ljcg8WfMfw, ControllerId: 2
%7|1502285441.278|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62954/4: 3 brokers, 0 topics
%7|1502285441.278|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62954/4:   Broker #0/3: localhost:62952 NodeId 2
%7|1502285441.278|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62954/4:   Broker #1/3: localhost:62954 NodeId 4
%7|1502285441.278|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62954/4:   Broker #2/3: localhost:62953 NodeId 3
c = C.get_watermark_offsets(TopicPartition('test',1))
%7|1502285443.486|METADATA|rdkafka#consumer-4| [thrd:app]: Requesting metadata for 1/1 topics: query partition leaders
%7|1502285443.486|METADATA|rdkafka#consumer-4| [thrd:app]: localhost:62953/3: Request metadata for 1 topic(s): query partition leaders
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
cimpl.KafkaException: KafkaError{code=LEADER_NOT_AVAILABLE,val=5,str="Failed to get watermark offsets: Broker: Leader not available"}
>>> %7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3: ===== Received metadata (for 1 requested topics): query partition leaders =====
%7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3: ClusterId: rxqnDq58T5K4ljcg8WfMfw, ControllerId: 2
%7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3: 3 brokers, 1 topics
%7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3:   Broker #0/3: localhost:62952 NodeId 2
%7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3:   Broker #1/3: localhost:62954 NodeId 4
%7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3:   Broker #2/3: localhost:62953 NodeId 3
%7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3:   Topic #0/1: test with 4 partitions
%7|1502285443.487|METADATA|rdkafka#consumer-4| [thrd:main]: localhost:62953/3: 1/1 requested topic(s) seen in metadata

>>>
>>>
>>> c.get_watermark_offsets(TopicPartition('test',1))
%7|1502285454.620|OFFSET|rdkafka#consumer-4| [thrd:app]: localhost:62952/2: OffsetRequest (v0, opv 0) for 1 topic(s) and 1 partition(s)
%7|1502285454.620|OFFSET|rdkafka#consumer-4| [thrd:app]: localhost:62952/2: OffsetRequest (v0, opv 0) for 1 topic(s) and 1 partition(s)
(0L, 4L)

Checklist

Please provide the following information:

• librdkafka version (release number or git tag): 0.11.0
• Apache Kafka version: 0.10.2.1
• librdkafka client configuration:
• Operating system:
• Using the legacy Consumer
• Using the high-level KafkaConsumer
• Provide logs (with debug=.. as necessary) from librdkafka
• Provide broker log excerpts
• Critical issue

[tchap]

I am using confluent-kafka-go. I can confirm the issue. Calling GetMetadata before calling QueryWatermarkOffsets fixed the issue for me.

[edenhill]

This has been fixed

[mfontanini]

I'm using 0.9.5 (planning on upgrading soon) and hit this same issue when calling rd_kafka_offsets_for_times. Is this fixed across the board or is this fix just for this rd_kafka_query_watermark_offsets? I can't see any tagged commits with this issue so I'm not entirely sure.

[edenhill]

There were a number of fixes with regards to timeout and retry handling in v0.11.3 and v0.11.4,
so I believe all such functions should now behave correctly.
Commit 0cb19d8 (the bug reference in that commit is wrong though=

[mfontanini]

Great, I'll give it a try soon then!