From jira-return-10310-archive-asf-public=cust-asf.ponee.io@kafka.apache.org Tue Feb 27 08:53:09 2018 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx-eu-01.ponee.io (Postfix) with SMTP id A79ED180651 for ; Tue, 27 Feb 2018 08:53:08 +0100 (CET) Received: (qmail 97877 invoked by uid 500); 27 Feb 2018 07:53: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 97866 invoked by uid 99); 27 Feb 2018 07:53:07 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd4-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 27 Feb 2018 07:53:07 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd4-us-west.apache.org (ASF Mail Server at spamd4-us-west.apache.org) with ESMTP id E7D13C0466 for ; Tue, 27 Feb 2018 07:53:06 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd4-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -110.311 X-Spam-Level: X-Spam-Status: No, score=-110.311 tagged_above=-999 required=6.31 tests=[ENV_AND_HDR_SPF_MATCH=-0.5, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, T_RP_MATCHES_RCVD=-0.01, USER_IN_DEF_SPF_WL=-7.5, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd4-us-west.apache.org [10.40.0.11]) (amavisd-new, port 10024) with ESMTP id XgxA19aHUUoT for ; Tue, 27 Feb 2018 07:53:02 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id A42F35F5AF for ; Tue, 27 Feb 2018 07:53:01 +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 AAB80E028E for ; Tue, 27 Feb 2018 07:53: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 15C842408C for ; Tue, 27 Feb 2018 07:53:00 +0000 (UTC) Date: Tue, 27 Feb 2018 07:53:00 +0000 (UTC) From: "Hanlin Liu (JIRA)" To: jira@kafka.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (KAFKA-6595) Kafka connect commit offset incorrectly. MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 Hanlin Liu created KAFKA-6595: --------------------------------- Summary: Kafka connect commit offset incorrectly. Key: KAFKA-6595 URL: https://issues.apache.org/jira/browse/KAFKA-6595 Project: Kafka Issue Type: Bug Components: KafkaConnect Affects Versions: 0.10.2.0 Reporter: Hanlin Liu SourceTaskOffsetComitter calls commitOffset() and waits for all incomplete = records to be sent. While the task is stopped, commitOffset() is called aga= in by the final block in WorkerSourceTask.execute(), it will throw=C2=A0{{I= nvalid call to OffsetStorageWriter flush() while already flushing, the fram= ework should not allow this}}=C2=A0exception. This will trigger closing Pro= ducer without waiting the flush timeout. After 30 seconds, all incomplete records has been forcefully aborted. If th= e=C2=A0{{offset.flush.timeout.ms}}=C2=A0is configured larger than 30 second= s, WorkerSourceTask will consider those aborted records as sent within flus= h timeout, which results in incorrectly flushing the source offset. =C2=A0 {code:java} // code placeholder 2018-02-27 02:59:33,134 INFO=C2=A0 [] Stopping connector dp-sqlserver-conne= ctor-dptask_455 =C2=A0 [pool-3-thread-6][Worker.java:254] 2018-02-27 02:59:33,134 INFO=C2=A0 [] Stopped connector dp-sqlserver-connec= tor-dptask_455 =C2=A0 [pool-3-thread-6][Worker.java:264] 2018-02-27 02:59:34,121 ERROR [] Invalid call to OffsetStorageWriter flush(= ) while already flushing, the framework should not allow this =C2=A0 [pool-= 1-thread-13][OffsetStorageWriter.java:110] 2018-02-27 02:59:34,121 ERROR [] Task dp-sqlserver-connector-dptask_455-0 t= hrew an uncaught and unrecoverable exception =C2=A0 [pool-1-thread-13][Work= erTask.java:141] org.apache.kafka.connect.errors.ConnectException: OffsetStorageWriter is al= ready flushing =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.connect.storage.OffsetStora= geWriter.beginFlush(OffsetStorageWriter.java:112) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.connect.runtime.WorkerSourc= eTask.commitOffsets(WorkerSourceTask.java:294) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.connect.runtime.WorkerSourc= eTask.execute(WorkerSourceTask.java:177) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.connect.runtime.WorkerTask.= doRun(WorkerTask.java:139) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.connect.runtime.WorkerTask.= run(WorkerTask.java:182) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at java.util.concurrent.Executors$RunnableAdapt= er.call(Executors.java:511) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at java.util.concurrent.FutureTask.run(FutureTa= sk.java:266) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at java.util.concurrent.ThreadPoolExecutor.runW= orker(ThreadPoolExecutor.java:1142) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at java.util.concurrent.ThreadPoolExecutor$Work= er.run(ThreadPoolExecutor.java:617) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at java.lang.Thread.run(Thread.java:745) 2018-02-27 03:00:00,734 ERROR [] Graceful stop of task dp-sqlserver-connect= or-dptask_455-0 failed. =C2=A0 [pool-3-thread-1][Worker.java:405] 2018-02-27 03:00:04,126 INFO=C2=A0 [] Proceeding to force close the produce= r since pending requests could not be completed within timeout 30 ms. =C2= =A0 [pool-1-thread-13][KafkaProducer.java:713] 2018-02-27 03:00:04,127 ERROR [] dp-sqlserver-connector-dptask_455-0 failed= to send record to dptask_455.JF_TEST_11.jf_test_tab_8: {} =C2=A0 [kafka-pr= oducer-network-thread | producer-31][WorkerSourceTask.java:228] java.lang.IllegalStateException: Producer is closed forcefully. =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.clients.producer.internals.= RecordAccumulator.abortBatches(RecordAccumulator.java:522) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.clients.producer.internals.= RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:502) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at org.apache.kafka.clients.producer.internals.= Sender.run(Sender.java:147) =C2=A0 =C2=A0 =C2=A0 =C2=A0 at java.lang.Thread.run(Thread.java:745) 2018-02-27 03:00:09,920 INFO=C2=A0 [] Finished WorkerSourceTask{id=3Ddp-sql= server-connector-dptask_455-0} commitOffsets successfully in 47088 ms =C2= =A0 [pool-4-thread-1][WorkerSourceTask.java:371] {code} =C2=A0 =C2=A0 -- This message was sent by Atlassian JIRA (v7.6.3#76005)