Sarama: async producer not continuing to retry on errors updating the leader

[mdubbyap]

Versions

Sarama Version: 1.17
Kafka Version: 0.9.0.1
Go Version: 1.10.3

Configuration

c.Net.MaxOpenRequests = 5
c.Net.DialTimeout = 30 * time.Second
c.Net.ReadTimeout = 30 * time.Second
c.Net.WriteTimeout = 30 * time.Second
c.Net.SASL.Handshake = true

c.Metadata.Retry.Max = 3
c.Metadata.Retry.Backoff = 250 * time.Millisecond
c.Metadata.RefreshFrequency = 10 * time.Minute
c.Metadata.Full = true

c.Producer.MaxMessageBytes = 1000000
c.Producer.RequiredAcks = WaitForLocal
c.Producer.Timeout = 10 * time.Second
c.Producer.Partitioner = NewHashPartitioner
c.Producer.Retry.Max = 100
c.Producer.Retry.Backoff = 100 * time.Millisecond
c.Producer.Return.Errors = true
c.Producer.Return.Successes = true
c.Producer.CompressionLevel = CompressionLevelDefault
c.Producer.Flush.Frequency = time.Millisecond * 250
c.Producer.Flush.Messages = 3000
c.Producer.Flush.Bytes = 83886080

c.Consumer.Fetch.Min = 1
c.Consumer.Fetch.Default = 1024 * 1024
c.Consumer.Retry.Backoff = 2 * time.Second
c.Consumer.MaxWaitTime = 250 * time.Millisecond
c.Consumer.MaxProcessingTime = 100 * time.Millisecond
c.Consumer.Return.Errors = false
c.Consumer.Offsets.CommitInterval = 1 * time.Second
c.Consumer.Offsets.Initial = OffsetNewest

c.ClientID = "the zk GUID"
c.ChannelBufferSize = 256
c.Version = MinVersion
c.MetricRegistry = metrics.NewRegistry()

Logs

These are just some of the error messages i get back from that place in the code i provided below. The cluster eventually deals with itself just fine, so the rest of the log is likely not useful. Let me know if you want more.

"kafka: Failed to produce message to topic sf.quantizer.rawbus: kafka server: In the middle of a leadership election, there is currently no leader for this partition and hence it is unavailable for writes."

"kafka: Failed to produce message to topic sf.quantizer.rawbus: kafka server: Unexpected (unknown?) server error."

Problem Description

When kafka nodes fail, the client is stopping retrying early when getting errors updating the leader. If we get an error here https://github.com/Shopify/sarama/blob/master/async_producer.go#L470 we fail for that message.

I think the behavior shouldn't change for a message regardless on the place the failure occurs. I think retries should still be done till they expire in the hopes that even those apparently severe errors can be ridden out.

Thoughts?

I'm happy to do the work to fix this if you agree, but would love some pointers on how you would fix it.

matthew.

[eapache]

Retries are already happening in that case internal to the metadata update controlled by the c.Metadata.Retry config entries. Retrying again at the producer layer would I think be more confusing.

[mdubbyap]

My concern is that the messages are dropped (or at least returned on the error channel) before their retries are done. Sometimes immediately with no retries at all. I see no evidence that they're retried later. Are you telling me they are retried again after the metadata update is completed successfully?

[eapache]

No, I mean the metadata update itself is retried several times within the call to refreshMetadata.

[mdubbyap]

Again, my concern is the messages being dropped and not retried...

[eapache]

There's no functional difference between retrying the message (which would get to the same spot and fail the same way on the same metadata refresh) and just retrying the metadata refresh directly. The latter is much simpler so it's what I did.

[mdubbyap]

Perhaps i am not explaining myself well.

I have retries set to 100, and a backoff of 100ms, so i would not expect a particular message to be dropped on the ground until after 10seconds of trying. If you get an error in the refresh code that last longer than the retries for the metadata refresh on the first retry, you immediately drop that datapoint and, i assume, try again with the next one?

I am seeing the metadata refresh succeeding and everything quiescing in far less than 10 seconds, but i am seeing messages be dropped during that time.

[fcantournet]

Hum, yeah... this just cost me 2 days :sweat_smile:
So for what it's worth I find the current behavior of not retrying messages after the metadata fetch retry succeeded to be counter intuitive.
It wasn't intuitive to any of the devs/SRE I talked about it either, as all of them actually assured me of the opposite.
I think this shouldn't be the default behavior, but if it has to stay this way, it would probably be a good idea to add an explicit comment in the documentation for producer retries.

[dgsb]

Hello, can we have a status on this issue ? Is a fix planned ?

[probot-shopify[bot]]

Thank you for taking the time to raise this issue. However, it has not had any activity on it in the past 90 days and will be closed in 30 days if no updates occur.
Please check if the master branch has already resolved the issue since it was raised. If you believe the issue is still valid and you would like input from the maintainers then please comment to ask for it to be reviewed.