Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id A6E0E200D60 for ; Fri, 1 Dec 2017 09:23:09 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id A5613160C06; Fri, 1 Dec 2017 08:23:09 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 990CF160BFB for ; Fri, 1 Dec 2017 09:23:08 +0100 (CET) Received: (qmail 89834 invoked by uid 500); 1 Dec 2017 08:23:07 -0000 Mailing-List: contact jira-help@kafka.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: jira@kafka.apache.org Delivered-To: mailing list jira@kafka.apache.org Received: (qmail 89823 invoked by uid 99); 1 Dec 2017 08:23:07 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 01 Dec 2017 08:23:07 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id DE4F2180777 for ; Fri, 1 Dec 2017 08:23:06 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -100.001 X-Spam-Level: X-Spam-Status: No, score=-100.001 tagged_above=-999 required=6.31 tests=[RP_MATCHES_RCVD=-0.001, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id VxcDWfN1TrBy for ; Fri, 1 Dec 2017 08:23:01 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTP id ED2B95F1BA for ; Fri, 1 Dec 2017 08:23:00 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id 72AC6E0CA3 for ; Fri, 1 Dec 2017 08:23:00 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 250D821067 for ; Fri, 1 Dec 2017 08:23:00 +0000 (UTC) Date: Fri, 1 Dec 2017 08:23:00 +0000 (UTC) From: "Terence Yi (JIRA)" To: jira@kafka.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (KAFKA-6292) ReplicaManager not respect the rolled log MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Fri, 01 Dec 2017 08:23:09 -0000 [ https://issues.apache.org/jira/browse/KAFKA-6292?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Terence Yi updated KAFKA-6292: ------------------------------ Description: After the log segment rolled successfully will followed with a failed fetch with the rolled partition. Consumer constantly poll from the Kafka cluster, and consume the message in order and end with a manually commit for each record. Here is the log in consumer side: 2017-11-28 20:44:26.560 WARN XXXXX [HOSTNAME][device-message-subscriber-pool-3-thread-1] org.apache.kafka.clients.consumer.internals.Fetcher {} Unknown error fetching data for topic-partition DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3 Observe below ERROR log in server.log [2017-11-27 12:16:24,182] INFO Rolled new log segment for 'DDI.DISPATCHER.P_TVIN.W_SL.P_appx.P_ul.P_pos-3' in 1 ms. (kafka.log.Log) [2017-11-27 12:16:35,555] INFO Rolled new log segment for 'DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3' in 1 ms. (kafka.log.Log) [2017-11-27 12:16:35,569] ERROR [Replica Manager on Broker 4]: Error processing fetch operation on partition DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3, offset 12813782 (kafka.server.ReplicaManager) org.apache.kafka.common.KafkaException: java.io.EOFException: Failed to read `log header` from file channel `sun.nio.ch.FileChannelImpl@1a493fba`. Expected to read 17 bytes, but reached end of file after reading 0 bytes. Started read from position 2147483635. at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:40) at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:24) at org.apache.kafka.common.utils.AbstractIterator.maybeComputeNext(AbstractIterator.java:79) at org.apache.kafka.common.utils.AbstractIterator.hasNext(AbstractIterator.java:45) at org.apache.kafka.common.record.FileRecords.searchForOffsetWithSize(FileRecords.java:279) at kafka.log.LogSegment.translateOffset(LogSegment.scala:176) at kafka.log.LogSegment.read(LogSegment.scala:228) at kafka.log.Log.read(Log.scala:938) at kafka.server.ReplicaManager.read$1(ReplicaManager.scala:719) at kafka.server.ReplicaManager.$anonfun$readFromLocalLog$6(ReplicaManager.scala:780) at scala.collection.mutable.ResizableArray.foreach(ResizableArray.scala:59) at scala.collection.mutable.ResizableArray.foreach$(ResizableArray.scala:52) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.server.ReplicaManager.readFromLocalLog(ReplicaManager.scala:779) at kafka.server.ReplicaManager.fetchMessages(ReplicaManager.scala:617) at kafka.server.KafkaApis.handleFetchRequest(KafkaApis.scala:615) at kafka.server.KafkaApis.handle(KafkaApis.scala:98) at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:66) at java.lang.Thread.run(Thread.java:745) Caused by: java.io.EOFException: Failed to read `log header` from file channel `sun.nio.ch.FileChannelImpl@1a493fba`. Expected to read 17 bytes, but reached end of file after reading 0 bytes. Started read from position 2147483635. at org.apache.kafka.common.utils.Utils.readFullyOrFail(Utils.java:751) at org.apache.kafka.common.record.FileLogInputStream.nextBatch(FileLogInputStream.java:66) at org.apache.kafka.common.record.FileLogInputStream.nextBatch(FileLogInputStream.java:40) at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:35) ... 18 more was: Consumer constantly poll from the Kafka cluster, and consume the message in order and end with a manually commit for each record. Here is the log in consumer side: 2017-11-28 20:44:26.560 WARN XXXXX [HOSTNAME][device-message-subscriber-pool-3-thread-1] org.apache.kafka.clients.consumer.internals.Fetcher {} Unknown error fetching data for topic-partition DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3 Observe below ERROR log in server.log [2017-11-27 12:16:24,182] INFO Rolled new log segment for 'DDI.DISPATCHER.P_TVIN.W_SL.P_appx.P_ul.P_pos-3' in 1 ms. (kafka.log.Log) [2017-11-27 12:16:35,555] INFO Rolled new log segment for 'DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3' in 1 ms. (kafka.log.Log) [2017-11-27 12:16:35,569] ERROR [Replica Manager on Broker 4]: Error processing fetch operation on partition DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3, offset 12813782 (kafka.server.ReplicaManager) org.apache.kafka.common.KafkaException: java.io.EOFException: Failed to read `log header` from file channel `sun.nio.ch.FileChannelImpl@1a493fba`. Expected to read 17 bytes, but reached end of file after reading 0 bytes. Started read from position 2147483635. at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:40) at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:24) at org.apache.kafka.common.utils.AbstractIterator.maybeComputeNext(AbstractIterator.java:79) at org.apache.kafka.common.utils.AbstractIterator.hasNext(AbstractIterator.java:45) at org.apache.kafka.common.record.FileRecords.searchForOffsetWithSize(FileRecords.java:279) at kafka.log.LogSegment.translateOffset(LogSegment.scala:176) at kafka.log.LogSegment.read(LogSegment.scala:228) at kafka.log.Log.read(Log.scala:938) at kafka.server.ReplicaManager.read$1(ReplicaManager.scala:719) at kafka.server.ReplicaManager.$anonfun$readFromLocalLog$6(ReplicaManager.scala:780) at scala.collection.mutable.ResizableArray.foreach(ResizableArray.scala:59) at scala.collection.mutable.ResizableArray.foreach$(ResizableArray.scala:52) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.server.ReplicaManager.readFromLocalLog(ReplicaManager.scala:779) at kafka.server.ReplicaManager.fetchMessages(ReplicaManager.scala:617) at kafka.server.KafkaApis.handleFetchRequest(KafkaApis.scala:615) at kafka.server.KafkaApis.handle(KafkaApis.scala:98) at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:66) at java.lang.Thread.run(Thread.java:745) Caused by: java.io.EOFException: Failed to read `log header` from file channel `sun.nio.ch.FileChannelImpl@1a493fba`. Expected to read 17 bytes, but reached end of file after reading 0 bytes. Started read from position 2147483635. at org.apache.kafka.common.utils.Utils.readFullyOrFail(Utils.java:751) at org.apache.kafka.common.record.FileLogInputStream.nextBatch(FileLogInputStream.java:66) at org.apache.kafka.common.record.FileLogInputStream.nextBatch(FileLogInputStream.java:40) at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:35) ... 18 more > ReplicaManager not respect the rolled log > ----------------------------------------- > > Key: KAFKA-6292 > URL: https://issues.apache.org/jira/browse/KAFKA-6292 > Project: Kafka > Issue Type: Bug > Components: log > Affects Versions: 0.11.0.0 > Environment: OS:Red Hat Enterprise Linux Server release 7.3 (Maipo) > Kafka: kafka_2.12-0.11.0.0 > JDK: jdk1.8.0_121 > Reporter: Terence Yi > > After the log segment rolled successfully will followed with a failed fetch with the rolled partition. > Consumer constantly poll from the Kafka cluster, and consume the message in order and end with a manually commit for each record. > Here is the log in consumer side: > 2017-11-28 20:44:26.560 WARN XXXXX [HOSTNAME][device-message-subscriber-pool-3-thread-1] org.apache.kafka.clients.consumer.internals.Fetcher {} Unknown error fetching data for topic-partition DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3 > Observe below ERROR log in server.log > [2017-11-27 12:16:24,182] INFO Rolled new log segment for 'DDI.DISPATCHER.P_TVIN.W_SL.P_appx.P_ul.P_pos-3' in 1 ms. (kafka.log.Log) > [2017-11-27 12:16:35,555] INFO Rolled new log segment for 'DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3' in 1 ms. (kafka.log.Log) > [2017-11-27 12:16:35,569] ERROR [Replica Manager on Broker 4]: Error processing fetch operation on partition DDI.DISPATCHER.MESSAGE_FORWARD_d694b9fa-d99a-4f4d-9062-b75e73b466a0-3, offset 12813782 (kafka.server.ReplicaManager) > org.apache.kafka.common.KafkaException: java.io.EOFException: Failed to read `log header` from file channel `sun.nio.ch.FileChannelImpl@1a493fba`. Expected to read 17 bytes, but reached end of file after reading 0 bytes. Started read from position 2147483635. > at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:40) > at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:24) > at org.apache.kafka.common.utils.AbstractIterator.maybeComputeNext(AbstractIterator.java:79) > at org.apache.kafka.common.utils.AbstractIterator.hasNext(AbstractIterator.java:45) > at org.apache.kafka.common.record.FileRecords.searchForOffsetWithSize(FileRecords.java:279) > at kafka.log.LogSegment.translateOffset(LogSegment.scala:176) > at kafka.log.LogSegment.read(LogSegment.scala:228) > at kafka.log.Log.read(Log.scala:938) > at kafka.server.ReplicaManager.read$1(ReplicaManager.scala:719) > at kafka.server.ReplicaManager.$anonfun$readFromLocalLog$6(ReplicaManager.scala:780) > at scala.collection.mutable.ResizableArray.foreach(ResizableArray.scala:59) > at scala.collection.mutable.ResizableArray.foreach$(ResizableArray.scala:52) > at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) > at kafka.server.ReplicaManager.readFromLocalLog(ReplicaManager.scala:779) > at kafka.server.ReplicaManager.fetchMessages(ReplicaManager.scala:617) > at kafka.server.KafkaApis.handleFetchRequest(KafkaApis.scala:615) > at kafka.server.KafkaApis.handle(KafkaApis.scala:98) > at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:66) > at java.lang.Thread.run(Thread.java:745) > Caused by: java.io.EOFException: Failed to read `log header` from file channel `sun.nio.ch.FileChannelImpl@1a493fba`. Expected to read 17 bytes, but reached end of file after reading 0 bytes. Started read from position 2147483635. > at org.apache.kafka.common.utils.Utils.readFullyOrFail(Utils.java:751) > at org.apache.kafka.common.record.FileLogInputStream.nextBatch(FileLogInputStream.java:66) > at org.apache.kafka.common.record.FileLogInputStream.nextBatch(FileLogInputStream.java:40) > at org.apache.kafka.common.record.RecordBatchIterator.makeNext(RecordBatchIterator.java:35) > ... 18 more -- This message was sent by Atlassian JIRA (v6.4.14#64029)