Hi Neeraj, However, I am unclear what the record-error-rate|total metric for a > producer means, > Does the metric get incremented only when the record could not make it to > the topic or even when there was a transient/retriable error trying to send > the message to the topic ?
The latter - so in your example, the error rate and retry rate metrics would both show an increase, but the records were eventually successfully sent. Would a metric for "batches that exhausted retries and so were dropped" be of any use to you? If so, I can propose adding one, and see what people think. Cheers, Liam Clarke-Hutchinson On Mon, 4 Apr 2022 at 19:29, Neeraj Vaidya <neeraj.vai...@yahoo.co.in.invalid> wrote: > Thank you David and Liam for your excellent responses. > Checking in the consumer will be extremely difficult. > However, I am unclear what the record-error-rate|total metric for a > producer means, > Does the metric get incremented only when the record could not make it to > the topic or even when there was a transient/retriable error trying to send > the message to the topic ? > > I am posting below the producer properties that I am using. > > acks = -1 > batch.size = 16384 > bootstrap.servers = [##MASKED##] > buffer.memory = 23622320128 > client.dns.lookup = use_all_dns_ips > client.id = producer-1 > compression.type = none > connections.max.idle.ms = 540000 > delivery.timeout.ms = 2880000 > enable.idempotence = true > interceptor.classes = [] > internal.auto.downgrade.txn.commit = false > key.serializer = class > org.apache.kafka.common.serialization.StringSerializer > linger.ms = 0 > max.block.ms = 1440000 > max.in.flight.requests.per.connection = 5 > max.request.size = 1048576 > metadata.max.age.ms = 7200000 > metadata.max.idle.ms = 7200000 > metric.reporters = [] > metrics.num.samples = 2 > metrics.recording.level = INFO > metrics.sample.window.ms = 30000 > partitioner.class = class > org.apache.kafka.clients.producer.internals.DefaultPartitioner > receive.buffer.bytes = 32768 > reconnect.backoff.max.ms = 1000 > reconnect.backoff.ms = 50 > request.timeout.ms = 30000 > retries = 2147483647 > retry.backoff.ms = 100 > sasl.client.callback.handler.class = null > sasl.jaas.config = null > sasl.kerberos.kinit.cmd = /usr/bin/kinit > sasl.kerberos.min.time.before.relogin = 60000 > sasl.kerberos.service.name = null > sasl.kerberos.ticket.renew.jitter = 0.05 > sasl.kerberos.ticket.renew.window.factor = 0.8 > sasl.login.callback.handler.class = null > sasl.login.class = null > sasl.login.refresh.buffer.seconds = 300 > sasl.login.refresh.min.period.seconds = 60 > sasl.login.refresh.window.factor = 0.8 > sasl.login.refresh.window.jitter = 0.05 > sasl.mechanism = GSSAPI > security.protocol = PLAINTEXT > security.providers = null > send.buffer.bytes = 131072 > ssl.cipher.suites = null > ssl.enabled.protocols = [TLSv1.2, TLSv1.3] > ssl.endpoint.identification.algorithm = https > ssl.engine.factory.class = null > ssl.key.password = null > ssl.keymanager.algorithm = SunX509 > ssl.keystore.location = null > ssl.keystore.password = null > ssl.keystore.type = JKS > ssl.protocol = TLSv1.3 > ssl.provider = null > ssl.secure.random.implementation = null > ssl.trustmanager.algorithm = PKIX > ssl.truststore.location = null > ssl.truststore.password = null > ssl.truststore.type = JKS > transaction.timeout.ms = 60000 > transactional.id = null > value.serializer = class > io.vertx.kafka.client.serialization.JsonObjectSerializer > > Regards, > Neeraj On Monday, 4 April, 2022, 03:19:08 pm GMT+10, David Finnie < > david.fin...@infrasoft.com.au> wrote: > > Hi Neeraj, > > I don't know what might be causing the first Produce error. Is the > OUT_OF_ORDER_SEQUENCE_NUMBER the first Produce error? From the error > that you included (Invalid sequence number for new epoch) it would seem > that the broker doesn't (yet) know about the Producer's epoch - possibly > because it is still catching up after you restarted it? Note that the > first sequence number for a new epoch must be 0, so if the broker thinks > that it is a new epoch, but the sequence number is 3, it will cause this > error. > > I can explain more about the relationship of Producer ID, Producer Epoch > and Sequence Number if you want. > > With 5 in-flight requests per connection, if any Produce is rejected, > all other in-flight Produce requests will be rejected with > OUT_OF_ORDER_SEQUENCE_NUMBER because the first rejected Produce > request's sequence number range never got stored, so all subsequent > in-flight Produce requests are out of sequence. (e.g. if a Produce with > sequence number 2 is rejected, and further Produce requests have already > been sent with sequence numbers 3, 4 and 5, after sequence number 2 is > rejected, the broker is still expecting the next sequence number to be > 2, and so will reject sequence numbers 3, 4, 5 with this error.) > > When a Produce request is rejected, the Producer code first waits for > responses to arrive for all in-flight Produce requests, and does not > send any new Produce requests until all responses are received. The > reason is that it doesn't know whether the other requests will receive > rejections simply of OUT_OF_ORDER_SEQUENCE_NUMBER, or some other > rejection reason. It needs to wait so that it knows which record batches > to retry. > > It is most likely that the poor performance you are seeing is due to the > need to wait for in-flight Produce requests to receive responses. There > is therefore less throughput achievable during such error recovery > times. Additionally, any in-flight Produce requests that are deemed > retriable need to be re-sent, so there is a doubling up of their network > traffic. > > Does this poor performance last for a long time? I would have thought > that it should be just a minor hiccup in performance, because the > Producer will increment the epoch, and reset sequence numbers from 0. > That should then allow for resumption of normal traffic for that > Producer ID on that partition. > > Re. whether the records made it to the topic, they should have. The log > messages indicate that it is retrying the records, and incrementing the > epoch and resequencing is part of that process. Of course, you should > probably check by setting up a consumer to ensure that all messages made > it to the topic, if that is feasible. > > David Finnie > > Infrasoft Pty Limited > > On 4/04/2022 12:42, Neeraj Vaidya wrote: > > Hi Liam, > > Thanks for getting back. > > > > 1) Producer settings ( I am guessing these are the ones you are > interested in) > > enable.idempotence=true > > max.in.flight.requests.per.connection=5 > > > > 2) Sample broker logs corresponding to the timestamp in the application > logs of the Producer > > > > [2022-04-03 15:56:39,587] ERROR [ReplicaManager broker=5] Error > processing append operation on partition input-topic-114 > (kafka.server.ReplicaManager) > > org.apache.kafka.common.errors.OutOfOrderSequenceException: Invalid > sequence number for new epoch at offset 967756 in partition > input-topic-114: 158 (request epoch), 3 (seq. number) > > > > Do the producer errors indicate that these messages never made it to the > Kafka topic at all ? > > > > Regards, > > Neeraj > > On Monday, 4 April, 2022, 12:23:30 pm GMT+10, Liam > Clarke-Hutchinson<lclar...@redhat.com> wrote: > > > > Hi Neeraj, > > > > First off, what are your producer settings? > > Secondly, do you have brokers logs for the leaders of some of your > affected > > topics on hand at all? > > > > Cheers, > > > > Liam Clarke-Hutchinson > > > > On Mon, 4 Apr 2022 at 14:04, Neeraj Vaidya > > <neeraj.vai...@yahoo.co.in.invalid> wrote: > > > >> Hi All, > >> For one of the Kafka producers that I have, I see that the Producer > Record > >> Error rate is non-zero i.e. out of the expected 3000 messages per second > >> which I a expect to be producing to the topic, I can see that this > metric > >> shows a rate of about 200. > >> Does this indicate that the records failed to be sent to the Kafka > topic, > >> or does this metric show up even for each retry in the Producer.Send > >> operation ? > >> > >> Notes : > >> 1) I have distributed 8 brokers equally across 2 sites. Using > >> rack-awareness, I am making Kafka position replicas equally across both > >> sites. My min.isr=2 and replication factor = 4. This makes 2 replicas > to be > >> located in each site. > >> 2) The scenario I am testing is that of shutting down a set of 4 brokers > >> in one site (out of 8) for an extended period of time and then bringing > >> them back up after say 2 hours. This causes the the follower replicas on > >> those brokers to try and catch-up with the leader replicas on the other > >> brokers. The error rate that I am referring to shows up under this > scenario > >> of restarting the brokers. It does not show up when I have just the > other > >> set of (4) brokers. > >> > >> To be specific, here are the errors that I see in the Kafka producer log > >> file: > >> > >> 2022-04-03 15:56:39.613 WARN --- [-thread | producer-1] > >> o.a.k.c.p.i.Sender : [Producer clientId=producer-1] > >> Got error produce response with correlation id 16512434 on > topic-partition > >> input-topic-114, retrying (2147483646 attempts left). Error: > >> OUT_OF_ORDER_SEQUENCE_NUMBER > >> 2022-04-03 15:56:39.613 WARN --- [-thread | producer-1] > >> o.a.k.c.p.i.Sender : [Producer clientId=producer-1] > >> Got error produce response with correlation id 16512434 on > topic-partition > >> input-topic-58, retrying (2147483646 attempts left). Error: > >> OUT_OF_ORDER_SEQUENCE_NUMBER > >> 2022-04-03 15:56:39.613 INFO --- [-thread | producer-1] > >> o.a.k.c.p.i.TransactionManager : [Producer clientId=producer-1] > >> ProducerId set to 2040 with epoch 159 > >> 2022-04-03 15:56:39.613 INFO --- [-thread | producer-1] > >> o.a.k.c.p.i.ProducerBatch : Resetting sequence number of > >> batch with current sequence 3 for partition input-topic-114 to 0 > >> 2022-04-03 15:56:39.613 INFO --- [-thread | producer-1] > >> o.a.k.c.p.i.ProducerBatch : Resetting sequence number of > >> batch with current sequence 5 for partition input-topic-114 to 2 > >> 2022-04-03 15:56:39.613 INFO --- [-thread | producer-1] > >> o.a.k.c.p.i.ProducerBatch : Resetting sequence number of > >> batch with current sequence 6 for partition input-topic-114 to 3 > >> 2022-04-03 15:56:39.613 INFO --- [-thread | producer-1] > >> o.a.k.c.p.i.ProducerBatch : Resetting sequence number of > >> batch with current sequence 1 for partition input-topic-58 to 0 > >> 2022-04-03 15:56:39.739 WARN --- [-thread | producer-1] > >> o.a.k.c.p.i.Sender : [Producer clientId=producer-1] > >> Got error produce response with correlation id 16512436 on > topic-partition > >> input-topic-82, retrying (2147483646 attempts left). Error: > >> OUT_OF_ORDER_SEQUENCE_NUMBER > >> > >> Regards, > >> Neeraj > >> > >> > > >
