Kafka
  1. Kafka
  2. KAFKA-1124

Sending to a new topic (with auto.create.topics.enable) returns ERROR

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 0.8.0, 0.8.1
    • Fix Version/s: 0.8.2.0
    • Component/s: None
    • Labels:

      Description

      I had thought this was reported issue, but can't seem to find a previous report for it.

      If auto.create.topics.enable is true, a producer still gets an ERROR logged on the first attempt to send a message to a new topic, e.g.:

      2013-11-06 03:00:08,638 ERROR [Thread-1] async.DefaultEventHandler - Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: mynewtopic
      2013-11-06 03:00:08,638 INFO [Thread-1] async.DefaultEventHandler - Back off for 100 ms before retrying send. Remaining retries = 3

      This usually clears itself up immediately on retry (after 100 ms), as handled by the the kafka.producer.async.DefaultEventHandler (with retries enabled).

      However, this is logged to the client as an ERROR, and looks scary, when in fact it should have been a normal operation (since we have auto.create.topics.enable=true).

      There should be a better interaction here between the producer client and the server.

      Perhaps the server can create the topic in flight before returning the metadata request.

      Or, if it needs to be asynchronous, it could return a code which indicates something like: "The topic doesn't exist yet, it is being created, try again shortly".....and have the client automatically retry (even if retries not enabled, since it's not an ERROR condition, really).

      The ERROR log level is a problem since apps often have alert systems set up to notify when any ERROR happens, etc.....

        Activity

        Hide
        Manikumar Reddy added a comment -

        This got fixed in new producer.

        Show
        Manikumar Reddy added a comment - This got fixed in new producer.
        Hide
        Joel Koshy added a comment -

        We should have an 0.8.2 release before that which has the new producer.

        Show
        Joel Koshy added a comment - We should have an 0.8.2 release before that which has the new producer.
        Hide
        Guozhang Wang added a comment -

        It will be in the 0.9 release, whose timeline has not been finalized yet. But we are shooting for this fall.

        Show
        Guozhang Wang added a comment - It will be in the 0.9 release, whose timeline has not been finalized yet. But we are shooting for this fall.
        Hide
        Jason Rosenberg added a comment -

        when will it be part of the 'released' version of kafka? Or it already there? We're currently using 0.8.0 still....

        Show
        Jason Rosenberg added a comment - when will it be part of the 'released' version of kafka? Or it already there? We're currently using 0.8.0 still....
        Hide
        Guozhang Wang added a comment -

        The new producer is already available now in the clients package in trunk.

        Show
        Guozhang Wang added a comment - The new producer is already available now in the clients package in trunk.
        Hide
        Jason Rosenberg added a comment -

        Yes, I think it sounds like it would......when is the 'new producer' going to be available?

        Show
        Jason Rosenberg added a comment - Yes, I think it sounds like it would......when is the 'new producer' going to be available?
        Hide
        Guozhang Wang added a comment -

        Hi Jason, in the new producer the retry would not log as an error, and only when all retries have exhausted it will report an error. While at the same time both retry rate and error rate will be reported in DMX. Would this resolve your problem?

        Show
        Guozhang Wang added a comment - Hi Jason, in the new producer the retry would not log as an error, and only when all retries have exhausted it will report an error. While at the same time both retry rate and error rate will be reported in DMX. Would this resolve your problem?
        Hide
        Jason Rosenberg added a comment -

        Well, not sure if that will do the right thing when there really is an ERROR when a producer gets an error sending to a broker. However, I think would would make sense, is to only log ERROR if we've run out of retry attempts and have truly given up on sending the message. So, if it's a failure that will be retried, it could be logged as WARN or even INFO. But I'm guessing that change is not specific to the initial auto-topic-creation case, it affects logging for all cases. But yeah, I think that sounds good to me.

        Show
        Jason Rosenberg added a comment - Well, not sure if that will do the right thing when there really is an ERROR when a producer gets an error sending to a broker. However, I think would would make sense, is to only log ERROR if we've run out of retry attempts and have truly given up on sending the message. So, if it's a failure that will be retried, it could be logged as WARN or even INFO. But I'm guessing that change is not specific to the initial auto-topic-creation case, it affects logging for all cases. But yeah, I think that sounds good to me.
        Hide
        Hanish Bansal added a comment -

        Could it be handled by just changing the message level from Error to INFO and presenting some informative message?

        If that so this issue can be released in 0.8.1.1 .

        Show
        Hanish Bansal added a comment - Could it be handled by just changing the message level from Error to INFO and presenting some informative message? If that so this issue can be released in 0.8.1.1 .
        Hide
        Robin Yamaguchi added a comment -

        I'm running 0.8.1. and only run into this issue with auto created topic when replication-factor is greater than 1. When topics are manually created, no errors.

        [root@h-kafka01-1b.use01.ho.priv kafka]# ./bin/kafka-console-producer.sh --broker-list h-kafka01:9092,h-kafka02:9092,h-kafka03:9092 --topic RobinTest4
        Test Message One, testing auto topic creation
        [2014-03-26 23:25:24,253] WARN Error while fetching metadata [

        {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,289] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}

        ] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,290] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler)
        [2014-03-26 23:25:24,406] WARN Error while fetching metadata [

        {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,434] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}

        ] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,434] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler)
        [2014-03-26 23:25:24,545] WARN Error while fetching metadata [

        {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,561] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}

        ] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,561] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler)
        [2014-03-26 23:25:24,669] WARN Error while fetching metadata [

        {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,683] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}

        ] for topic [RobinTest4]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)
        [2014-03-26 23:25:24,683] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler)
        [2014-03-26 23:25:24,817] ERROR Failed to send requests for topics RobinTest4 with correlation ids in [0,8] (kafka.producer.async.DefaultEventHandler)
        [2014-03-26 23:25:24,819] ERROR Error in handling batch of 1 events (kafka.producer.async.ProducerSendThread)
        kafka.common.FailedToSendMessageException: Failed to send messages after 3 tries.
        at kafka.producer.async.DefaultEventHandler.handle(DefaultEventHandler.scala:90)
        at kafka.producer.async.ProducerSendThread.tryToHandle(ProducerSendThread.scala:104)
        at kafka.producer.async.ProducerSendThread$$anonfun$processEvents$3.apply(ProducerSendThread.scala:87)
        at kafka.producer.async.ProducerSendThread$$anonfun$processEvents$3.apply(ProducerSendThread.scala:67)
        at scala.collection.immutable.Stream.foreach(Stream.scala:526)
        at kafka.producer.async.ProducerSendThread.processEvents(ProducerSendThread.scala:66)
        at kafka.producer.async.ProducerSendThread.run(ProducerSendThread.scala:44)

        Show
        Robin Yamaguchi added a comment - I'm running 0.8.1. and only run into this issue with auto created topic when replication-factor is greater than 1. When topics are manually created, no errors. [root@h-kafka01-1b.use01.ho.priv kafka] # ./bin/kafka-console-producer.sh --broker-list h-kafka01:9092,h-kafka02:9092,h-kafka03:9092 --topic RobinTest4 Test Message One, testing auto topic creation [2014-03-26 23:25:24,253] WARN Error while fetching metadata [ {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,289] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException} ] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,290] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler) [2014-03-26 23:25:24,406] WARN Error while fetching metadata [ {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,434] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException} ] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,434] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler) [2014-03-26 23:25:24,545] WARN Error while fetching metadata [ {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,561] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException} ] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,561] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler) [2014-03-26 23:25:24,669] WARN Error while fetching metadata [ {TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException}] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,683] WARN Error while fetching metadata [{TopicMetadata for topic RobinTest4 -> No partition metadata for topic RobinTest4 due to kafka.common.LeaderNotAvailableException} ] for topic [RobinTest4] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo) [2014-03-26 23:25:24,683] ERROR Failed to collate messages by topic, partition due to: Failed to fetch topic metadata for topic: RobinTest4 (kafka.producer.async.DefaultEventHandler) [2014-03-26 23:25:24,817] ERROR Failed to send requests for topics RobinTest4 with correlation ids in [0,8] (kafka.producer.async.DefaultEventHandler) [2014-03-26 23:25:24,819] ERROR Error in handling batch of 1 events (kafka.producer.async.ProducerSendThread) kafka.common.FailedToSendMessageException: Failed to send messages after 3 tries. at kafka.producer.async.DefaultEventHandler.handle(DefaultEventHandler.scala:90) at kafka.producer.async.ProducerSendThread.tryToHandle(ProducerSendThread.scala:104) at kafka.producer.async.ProducerSendThread$$anonfun$processEvents$3.apply(ProducerSendThread.scala:87) at kafka.producer.async.ProducerSendThread$$anonfun$processEvents$3.apply(ProducerSendThread.scala:67) at scala.collection.immutable.Stream.foreach(Stream.scala:526) at kafka.producer.async.ProducerSendThread.processEvents(ProducerSendThread.scala:66) at kafka.producer.async.ProducerSendThread.run(ProducerSendThread.scala:44)
        Hide
        Jason Rosenberg added a comment -

        status?

        Show
        Jason Rosenberg added a comment - status?
        Hide
        Anuj Mehta added a comment -

        Hi Jason Rosenberg

        Just checked again. Yes there is an ERROR message in producer logs. Let me check if I can fix this

        Show
        Anuj Mehta added a comment - Hi Jason Rosenberg Just checked again. Yes there is an ERROR message in producer logs. Let me check if I can fix this
        Hide
        Jason Rosenberg added a comment -

        Anuj Mehta are you looking in the logs for the producer, or the server? The ERROR I see is in the producer. It does go on to complain aobut LeaderNotAvailable, etc., but it also gives me the ERROR message.

        I'm using 0.8, sha: cd3b79699341afb8d52c51d9ac7317d93c32eeb6 (dated Oct 16). Which version are you using?

        Jason

        Show
        Jason Rosenberg added a comment - Anuj Mehta are you looking in the logs for the producer, or the server? The ERROR I see is in the producer. It does go on to complain aobut LeaderNotAvailable, etc., but it also gives me the ERROR message. I'm using 0.8, sha: cd3b79699341afb8d52c51d9ac7317d93c32eeb6 (dated Oct 16). Which version are you using? Jason
        Hide
        Anuj Mehta added a comment -

        Hi

        I tried reproducing this issue but I am getting a WARN message instead of an ERROR

        [2013-11-13 18:24:59,310] WARN Error while fetching metadata [

        {TopicMetadata for topic newTopic -> No partition metadata for topic newTopic due to kafka.common.LeaderNotAvailableException}

        ] for topic [newTopic]: class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)

        Show
        Anuj Mehta added a comment - Hi I tried reproducing this issue but I am getting a WARN message instead of an ERROR [2013-11-13 18:24:59,310] WARN Error while fetching metadata [ {TopicMetadata for topic newTopic -> No partition metadata for topic newTopic due to kafka.common.LeaderNotAvailableException} ] for topic [newTopic] : class kafka.common.LeaderNotAvailableException (kafka.producer.BrokerPartitionInfo)

          People

          • Assignee:
            Unassigned
            Reporter:
            Jason Rosenberg
          • Votes:
            2 Vote for this issue
            Watchers:
            10 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development