From jira-return-8846-archive-asf-public=cust-asf.ponee.io@kafka.apache.org Tue Jan 16 20:02:05 2018 Return-Path: X-Original-To: archive-asf-public@eu.ponee.io Delivered-To: archive-asf-public@eu.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by mx-eu-01.ponee.io (Postfix) with ESMTP id 8F54D18065B for ; Tue, 16 Jan 2018 20:02:05 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 7EABB160C1D; Tue, 16 Jan 2018 19:02:05 +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 770F5160C34 for ; Tue, 16 Jan 2018 20:02:04 +0100 (CET) Received: (qmail 49425 invoked by uid 500); 16 Jan 2018 19:02:03 -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 49414 invoked by uid 99); 16 Jan 2018 19:02:03 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 16 Jan 2018 19:02:03 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id 3B0C71A2EC2 for ; Tue, 16 Jan 2018 19:02:03 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -99.91 X-Spam-Level: X-Spam-Status: No, score=-99.91 tagged_above=-999 required=6.31 tests=[KAM_ASCII_DIVIDERS=0.8, RCVD_IN_DNSWL_LOW=-0.7, SPF_PASS=-0.001, T_RP_MATCHES_RCVD=-0.01, URIBL_BLOCKED=0.001, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id bfKoslr4DRco for ; Tue, 16 Jan 2018 19:02: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 23F9D5F340 for ; Tue, 16 Jan 2018 19:02: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 9EEEDE095A for ; Tue, 16 Jan 2018 19:02: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 5B5B9212FD for ; Tue, 16 Jan 2018 19:02:00 +0000 (UTC) Date: Tue, 16 Jan 2018 19:02:00 +0000 (UTC) From: "Matthias J. Sax (JIRA)" To: jira@kafka.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (KAFKA-6269) KTable state restore fails after rebalance MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/KAFKA-6269?page=3Dcom.atlassian= .jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=3D1632= 7592#comment-16327592 ]=20 Matthias J. Sax commented on KAFKA-6269: ---------------------------------------- I would assume that branch `1.0` ([https://github.com/apache/kafka/tree/1.0= |https://github.com/apache/kafka/tree/1.0)])=C2=A0should be quite stable = =E2=80=93 it only contains bug fixes for `1.0.1`. As an alternative, you ca= n also checkout `1.0.0` commit ([https://github.com/apache/kafka/tree/1.0.0= |https://github.com/apache/kafka/tree/1.0.0)])=C2=A0and cherry-pick the fix= . Btw: Brokers are always backward compatible, to yes, KS 0.11.0.1 will work = with `1.0.0` brokers. > KTable state restore fails after rebalance > ------------------------------------------ > > Key: KAFKA-6269 > URL: https://issues.apache.org/jira/browse/KAFKA-6269 > Project: Kafka > Issue Type: Bug > Components: streams > Affects Versions: 1.0.0 > Reporter: Andreas Schroeder > Assignee: Bill Bejeck > Priority: Blocker > Fix For: 1.1.0, 1.0.1 > > > I have the following kafka streams topology: > entity-B -> map step -> entity-B-exists (with state store) > entity-A -> map step -> entity-A-exists (with state store) > (entity-B-exists, entity-A-exists) -> outer join with state store. > The topology building code looks like this (some data type, serde, valuem= apper, and joiner code omitted): > {code} > def buildTable[V](builder: StreamsBuilder, > sourceTopic: String, > existsTopic: String, > valueSerde: Serde[V], > valueMapper: ValueMapper[String, V]): KTable[St= ring, V] =3D { > val stream: KStream[String, String] =3D builder.stream[String, String](= sourceTopic) > val transformed: KStream[String, V] =3D stream.mapValues(valueMapper) > transformed.to(existsTopic, Produced.`with`(Serdes.String(), valueSerde= )) > val inMemoryStoreName =3D s"$existsTopic-persisted" > val materialized =3D Materialized.as(Stores.inMemoryKeyValueStore(inMem= oryStoreName)) > .withKeySerde(Serdes.String()) > .withValueSerde(valueSerde) > .withLoggingDisabled() > builder.table(existsTopic, materialized) > } > val builder =3D new StreamsBuilder > val mapToEmptyString: ValueMapper[String, String] =3D (value: String) =3D= > if (value !=3D null) "" else null > val entitiesB: KTable[String, EntityBInfo] =3D > buildTable(builder, > "entity-B", > "entity-B-exists", > EntityBInfoSerde, > ListingImagesToEntityBInfo) > val entitiesA: KTable[String, String] =3D > buildTable(builder, "entity-A", "entity-A-exists", Serdes.String(), map= ToEmptyString) > val joiner: ValueJoiner[String, EntityBInfo, EntityDiff] =3D (a, b) =3D> = EntityDiff.fromJoin(a, b) > val materialized =3D Materialized.as(Stores.inMemoryKeyValueStore("entity= -A-joined-with-entity-B")) > .withKeySerde(Serdes.String()) > .withValueSerde(EntityDiffSerde) > .withLoggingEnabled(new java.util.HashMap[String, String]()) > val joined: KTable[String, EntityDiff] =3D entitiesA.outerJoin(entitiesB,= joiner, materialized) > {code} > We run 4 processor machines with 30 stream threads each; each topic has 3= 0 partitions so that there is a total of 4 x 30 =3D 120 partitions to consu= me. The initial launch of the processor works fine, but when killing one pr= ocessor and letting him re-join the stream threads leads to some faulty beh= aviour. > Fist, the total number of assigned partitions over all processor machines= is larger than 120 (sometimes 157, sometimes just 132), so the partition /= task assignment seems to assign the same job to different stream threads. > The processor machines trying to re-join the consumer group fail constant= ly with the error message of 'Detected a task that got migrated to another = thread.' We gave the processor half an hour to recover; usually, rebuilding= the KTable states take around 20 seconds (with Kafka 0.11.0.1). > Here are the details of the errors we see: > stream-thread [kafka-processor-6-StreamThread-9] Detected a task that got= migrated to another thread. This implies that this thread missed a rebalan= ce and dropped out of the consumer group. Trying to rejoin the consumer gro= up now. > {code} > org.apache.kafka.streams.errors.TaskMigratedException: Log end offset of = entity-B-exists-0 should not change while restoring: old end offset 4750539= , current offset 4751388 > > StreamsTask taskId: 1_0 > > > =09ProcessorTopology: > > =09=09KSTREAM-SOURCE-0000000008: > > =09=09=09topics:=09=09[entity-A-exists] > > =09=09=09children:=09[KTABLE-SOURCE-0000000009] > > =09=09KTABLE-SOURCE-0000000009: > > =09=09=09states:=09=09[entity-A-exists-persisted] > > =09=09=09children:=09[KTABLE-JOINTHIS-0000000011] > > =09=09KTABLE-JOINTHIS-0000000011: > > =09=09=09states:=09=09[entity-B-exists-persisted] > > =09=09=09children:=09[KTABLE-MERGE-0000000010] > > =09=09KTABLE-MERGE-0000000010: > > =09=09=09states:=09=09[entity-A-joined-with-entity-B] > > =09=09KSTREAM-SOURCE-0000000003: > > =09=09=09topics:=09=09[entity-B-exists] > > =09=09=09children:=09[KTABLE-SOURCE-0000000004] > > =09=09KTABLE-SOURCE-0000000004: > > =09=09=09states:=09=09[entity-B-exists-persisted] > > =09=09=09children:=09[KTABLE-JOINOTHER-0000000012] > > =09=09KTABLE-JOINOTHER-0000000012: > > =09=09=09states:=09=09[entity-A-exists-persisted] > > =09=09=09children:=09[KTABLE-MERGE-0000000010] > > =09=09KTABLE-MERGE-0000000010: > > =09=09=09states:=09=09[entity-A-joined-with-entity-B] > > Partitions [entity-A-exists-0, entity-B-exists-0] > =09at org.apache.kafka.streams.processor.internals.StoreChangelogReader.r= estorePartition(StoreChangelogReader.java:242) > =09at org.apache.kafka.streams.processor.internals.StoreChangelogReader.r= estore(StoreChangelogReader.java:83) > =09at org.apache.kafka.streams.processor.internals.TaskManager.updateNewA= ndRestoringTasks(TaskManager.java:263) > =09at org.apache.kafka.streams.processor.internals.StreamThread.runOnce(S= treamThread.java:803) > =09at org.apache.kafka.streams.processor.internals.StreamThread.runLoop(S= treamThread.java:774) > =09at org.apache.kafka.streams.processor.internals.StreamThread.run(Strea= mThread.java:744) > {code} > That one surprises me: the KTable state store entity-B-exists-persisted i= s rebuilt from entity-B-exists that of course can change while the rebuild = is happening, since it the topic entity-B-exists is fed by another stream t= hread. > Another one, very similar: > {code} > org.apache.kafka.streams.errors.TaskMigratedException: Log end offset of = entity-A-exists-24 should not change while restoring: old end offset 648397= 8, current offset 6485108 > > StreamsTask taskId: 1_24 > > > =09ProcessorTopology: > > =09=09KSTREAM-SOURCE-0000000008: > > =09=09=09topics:=09=09[entity-A-exists] > > =09=09=09children:=09[KTABLE-SOURCE-0000000009] > > =09=09KTABLE-SOURCE-0000000009: > > =09=09=09states:=09=09[entity-A-exists-persisted] > > =09=09=09children:=09[KTABLE-JOINTHIS-0000000011] > > =09=09KTABLE-JOINTHIS-0000000011: > > =09=09=09states:=09=09[entity-B-exists-persisted] > > =09=09=09children:=09[KTABLE-MERGE-0000000010] > > =09=09KTABLE-MERGE-0000000010: > > =09=09=09states:=09=09[entity-A-joined-with-entity-B] > > =09=09KSTREAM-SOURCE-0000000003: > > =09=09=09topics:=09=09[entity-B-exists] > > =09=09=09children:=09[KTABLE-SOURCE-0000000004] > > =09=09KTABLE-SOURCE-0000000004: > > =09=09=09states:=09=09[entity-B-exists-persisted] > > =09=09=09children:=09[KTABLE-JOINOTHER-0000000012] > > =09=09KTABLE-JOINOTHER-0000000012: > > =09=09=09states:=09=09[entity-A-exists-persisted] > > =09=09=09children:=09[KTABLE-MERGE-0000000010] > > =09=09KTABLE-MERGE-0000000010: > > =09=09=09states:=09=09[entity-A-joined-with-entity-B] > > Partitions [entity-A-exists-24, entity-B-exists-24] > =09at org.apache.kafka.streams.processor.internals.StoreChangelogReader.r= estorePartition(StoreChangelogReader.java:242) > =09at org.apache.kafka.streams.processor.internals.StoreChangelogReader.r= estore(StoreChangelogReader.java:83) > =09at org.apache.kafka.streams.processor.internals.TaskManager.updateNewA= ndRestoringTasks(TaskManager.java:263) > =09at org.apache.kafka.streams.processor.internals.StreamThread.runOnce(S= treamThread.java:803) > =09at org.apache.kafka.streams.processor.internals.StreamThread.runLoop(S= treamThread.java:774) > =09at org.apache.kafka.streams.processor.internals.StreamThread.run(Strea= mThread.java:744) > {code} > Again, the topic entity-A-exists is fed by another stream thread. > We saw around 60000 such errors per minute, as the stream threads continu= ously try to recover and fail. -- This message was sent by Atlassian JIRA (v7.6.3#76005)