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 2B577200B74 for ; Thu, 1 Sep 2016 13:28:29 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 29A7C160AB5; Thu, 1 Sep 2016 11:28:29 +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 EDD26160AAE for ; Thu, 1 Sep 2016 13:28:27 +0200 (CEST) Received: (qmail 90598 invoked by uid 500); 1 Sep 2016 11:28:26 -0000 Mailing-List: contact dev-help@atlas.incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@atlas.incubator.apache.org Delivered-To: mailing list dev@atlas.incubator.apache.org Received: (qmail 90587 invoked by uid 99); 1 Sep 2016 11:28:26 -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; Thu, 01 Sep 2016 11:28:26 +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 6999EC000A for ; Thu, 1 Sep 2016 11:28:26 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd4-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -4.626 X-Spam-Level: X-Spam-Status: No, score=-4.626 tagged_above=-999 required=6.31 tests=[KAM_ASCII_DIVIDERS=0.8, KAM_LAZY_DOMAIN_SECURITY=1, RCVD_IN_DNSWL_HI=-5, RP_MATCHES_RCVD=-1.426] 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 RKNV7env6aJ6 for ; Thu, 1 Sep 2016 11:28:22 +0000 (UTC) Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with SMTP id 9116060CD1 for ; Thu, 1 Sep 2016 11:28:21 +0000 (UTC) Received: (qmail 89732 invoked by uid 99); 1 Sep 2016 11:28:20 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 01 Sep 2016 11:28:20 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 9873E2C1B83 for ; Thu, 1 Sep 2016 11:28:20 +0000 (UTC) Date: Thu, 1 Sep 2016 11:28:20 +0000 (UTC) From: "Ayub Khan (JIRA)" To: dev@atlas.incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (ATLAS-1153) When ATLAS_HOOK topic is not created by Atlas, it is not reading messages from the beginning MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 01 Sep 2016 11:28:29 -0000 [ https://issues.apache.org/jira/browse/ATLAS-1153?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15455125#comment-15455125 ] Ayub Khan commented on ATLAS-1153: ---------------------------------- Not sure [~yhemanth]. I will check and get back to you. > When ATLAS_HOOK topic is not created by Atlas, it is not reading messages from the beginning > -------------------------------------------------------------------------------------------- > > Key: ATLAS-1153 > URL: https://issues.apache.org/jira/browse/ATLAS-1153 > Project: Atlas > Issue Type: Bug > Affects Versions: trunk > Reporter: Ayub Khan > Fix For: trunk > > > When ATLAS_HOOK topic is not created by Atlas, it is not reading messages from the beginning > Steps to repro: > 1. Stop atlas. > 2. Delete ATLAS_HOOK Topic and check it is actually deleted. > 3. Create some hive tables(more than 3, preferrable) from hive client. > 4. Now check that ATLAS_HOOK topic is created and also has messages for above hive tables. > 5. Now restart Atlas. Ideally Atlas should start consuming messages from offset '0' but looks like it is consuming the latest one. > I have also verified that 'auto.offset.reset' is set to 'smallest', which should ideally force the consumer to read messages from offset '0'. > {noformat} > 2016-09-01 10:46:41,378 INFO - [main:] ~ Property auto.commit.enable is overridden to false (VerifiableProperties:68) > 2016-09-01 10:46:41,379 INFO - [main:] ~ Property auto.offset.reset is overridden to smallest (VerifiableProperties:68) > 2016-09-01 10:46:41,379 WARN - [main:] ~ Property bootstrap.servers is not valid (VerifiableProperties:83) > 2016-09-01 10:46:41,379 INFO - [main:] ~ Property group.id is overridden to atlas (VerifiableProperties:68) > 2016-09-01 10:46:41,379 WARN - [main:] ~ Property hook.group.id is not valid (VerifiableProperties:83) > 2016-09-01 10:46:41,379 WARN - [main:] ~ Property key.deserializer is not valid (VerifiableProperties:83) > 2016-09-01 10:46:41,380 WARN - [main:] ~ Property key.serializer is not valid (VerifiableProperties:83) > {noformat} > Kafka commands > {noformat} > [root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper 172.22.74.193:2181,172.22.74.192:2181 --list > ATLAS_ENTITIES > ATLAS_HOOK > __consumer_offsets > [root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper 172.22.74.193:2181,172.22.74.192:2181 --topic ATLAS_HOOK --delete > Topic ATLAS_HOOK is marked for deletion. > Note: This will have no impact if delete.topic.enable is not set to true. > [root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper 172.22.74.193:2181,172.22.74.192:2181 --list > ATLAS_ENTITIES > __consumer_offsets > {noformat} > Atlas logs showing initOffset set to 3, ideally this should be set to zero. > {noformat} > 2016-09-01 10:46:41,590 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], begin rebalancing consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0 (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,841 INFO - [main:] ~ [ConsumerFetcherManager-1472726801467] Stopping leader finder thread (ConsumerFetcherManager:68) > 2016-09-01 10:46:41,841 INFO - [main:] ~ [ConsumerFetcherManager-1472726801467] Stopping all fetchers (ConsumerFetcherManager:68) > 2016-09-01 10:46:41,842 INFO - [main:] ~ [ConsumerFetcherManager-1472726801467] All connections stopped (ConsumerFetcherManager:68) > 2016-09-01 10:46:41,843 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared all relevant queues for this fetcher (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,845 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared the data chunks in all the consumer message iterators (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,849 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Releasing partition ownership (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,900 INFO - [main:] ~ Starting round-robin assignment with consumers ArrayBuffer(atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c) (RoundRobinAssignor:68) > 2016-09-01 10:46:41,901 INFO - [main:] ~ Consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c rebalancing the following partitions for topic ATLAS_HOOK: ArrayBuffer(0) (RoundRobinAssignor:68) > 2016-09-01 10:46:41,955 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0 successfully owned partition 0 for topic ATLAS_HOOK (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,985 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c selected partitions : ATLAS_HOOK:0: fetched offset = 3: consumed offset = 3 (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,994 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], end rebalancing consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0 (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,997 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread], Starting (ConsumerFetcherManager$LeaderFinderThread:68) > 2016-09-01 10:46:42,013 INFO - [main:] ~ Initializing Spring root WebApplicationContext (/:2052) > 2016-09-01 10:46:42,014 INFO - [NotificationHookConsumer thread-0:] ~ Atlas Server is ready, can start reading Kafka events. (NotificationHookConsumer:305) > 2016-09-01 10:46:42,022 INFO - [main:] ~ Root WebApplicationContext: initialization started (ContextLoader:272) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Verifying properties (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property client.id is overridden to atlas (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property metadata.broker.list is overridden to atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667,atlas-pixie-dust-test-7-unsecure-3.openstacklocal:6667 (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property request.timeout.ms is overridden to 30000 (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property security.protocol is overridden to PLAINTEXT (VerifiableProperties:68) > 2016-09-01 10:46:42,092 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Fetching metadata from broker BrokerEndPoint(1001,atlas-pixie-dust-test-7-unsecure-1.openstacklocal,6667) with correlation id 0 for 1 topic(s) Set(ATLAS_HOOK) (ClientUtils$:68) > 2016-09-01 10:46:42,098 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Connected to atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667 for producing (SyncProducer:68) > 2016-09-01 10:46:42,135 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Disconnecting from atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667 (SyncProducer:68) > 2016-09-01 10:46:42,145 INFO - [main:] ~ Refreshing Root WebApplicationContext: startup date [Thu Sep 01 10:46:42 UTC 2016]; root of context hierarchy (XmlWebApplicationContext:503) > 2016-09-01 10:46:42,181 INFO - [ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002:] ~ [ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002], Starting (ConsumerFetcherThread:68) > 2016-09-01 10:46:42,190 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ [ConsumerFetcherManager-1472726801467] Added fetcher for partitions ArrayBuffer([[ATLAS_HOOK,0], initOffset 3 to broker BrokerEndPoint(1002,atlas-pixie-dust-test-7-unsecure-3.openstacklocal,6667)] ) (ConsumerFetcherManager:68) > {noformat} > Steps to repro: > 1. Stop atlas. > 2. Delete ATLAS_HOOK Topic and check it is actually deleted. > 3. Create some hive tables(more than 3, preferrable) from hive client. > 4. Now check that ATLAS_HOOK topic is created and also has messages for above hive tables. > 5. Now restart Atlas. Ideally Atlas should start consuming messages from offset '0' but looks like it is consuming the latest one. > I have also verified that 'auto.offset.reset' is set to 'smallest', which should ideally force the consumer to read messages from offset '0'. > {noformat} > 2016-09-01 10:46:41,378 INFO - [main:] ~ Property auto.commit.enable is overridden to false (VerifiableProperties:68) > 2016-09-01 10:46:41,379 INFO - [main:] ~ Property auto.offset.reset is overridden to smallest (VerifiableProperties:68) > 2016-09-01 10:46:41,379 WARN - [main:] ~ Property bootstrap.servers is not valid (VerifiableProperties:83) > 2016-09-01 10:46:41,379 INFO - [main:] ~ Property group.id is overridden to atlas (VerifiableProperties:68) > 2016-09-01 10:46:41,379 WARN - [main:] ~ Property hook.group.id is not valid (VerifiableProperties:83) > 2016-09-01 10:46:41,379 WARN - [main:] ~ Property key.deserializer is not valid (VerifiableProperties:83) > 2016-09-01 10:46:41,380 WARN - [main:] ~ Property key.serializer is not valid (VerifiableProperties:83) > {noformat} > Kafka commands > {noformat} > [root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper 172.22.74.193:2181,172.22.74.192:2181 --list > ATLAS_ENTITIES > ATLAS_HOOK > __consumer_offsets > [root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper 172.22.74.193:2181,172.22.74.192:2181 --topic ATLAS_HOOK --delete > Topic ATLAS_HOOK is marked for deletion. > Note: This will have no impact if delete.topic.enable is not set to true. > [root@atlas-pixie-dust-test-7-unsecure-1 bin]# ./kafka-topics.sh --zookeeper 172.22.74.193:2181,172.22.74.192:2181 --list > ATLAS_ENTITIES > __consumer_offsets > {noformat} > Atlas logs showing initOffset set to 3, ideally this should be set to zero. > {noformat} > 2016-09-01 10:46:41,590 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], begin rebalancing consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0 (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,841 INFO - [main:] ~ [ConsumerFetcherManager-1472726801467] Stopping leader finder thread (ConsumerFetcherManager:68) > 2016-09-01 10:46:41,841 INFO - [main:] ~ [ConsumerFetcherManager-1472726801467] Stopping all fetchers (ConsumerFetcherManager:68) > 2016-09-01 10:46:41,842 INFO - [main:] ~ [ConsumerFetcherManager-1472726801467] All connections stopped (ConsumerFetcherManager:68) > 2016-09-01 10:46:41,843 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared all relevant queues for this fetcher (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,845 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Cleared the data chunks in all the consumer message iterators (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,849 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Releasing partition ownership (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,900 INFO - [main:] ~ Starting round-robin assignment with consumers ArrayBuffer(atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c) (RoundRobinAssignor:68) > 2016-09-01 10:46:41,901 INFO - [main:] ~ Consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c rebalancing the following partitions for topic ATLAS_HOOK: ArrayBuffer(0) (RoundRobinAssignor:68) > 2016-09-01 10:46:41,955 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0 successfully owned partition 0 for topic ATLAS_HOOK (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,985 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], Consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c selected partitions : ATLAS_HOOK:0: fetched offset = 3: consumed offset = 3 (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,994 INFO - [main:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c], end rebalancing consumer atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c try #0 (ZookeeperConsumerConnector:68) > 2016-09-01 10:46:41,997 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread], Starting (ConsumerFetcherManager$LeaderFinderThread:68) > 2016-09-01 10:46:42,013 INFO - [main:] ~ Initializing Spring root WebApplicationContext (/:2052) > 2016-09-01 10:46:42,014 INFO - [NotificationHookConsumer thread-0:] ~ Atlas Server is ready, can start reading Kafka events. (NotificationHookConsumer:305) > 2016-09-01 10:46:42,022 INFO - [main:] ~ Root WebApplicationContext: initialization started (ContextLoader:272) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Verifying properties (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property client.id is overridden to atlas (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property metadata.broker.list is overridden to atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667,atlas-pixie-dust-test-7-unsecure-3.openstacklocal:6667 (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property request.timeout.ms is overridden to 30000 (VerifiableProperties:68) > 2016-09-01 10:46:42,058 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Property security.protocol is overridden to PLAINTEXT (VerifiableProperties:68) > 2016-09-01 10:46:42,092 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Fetching metadata from broker BrokerEndPoint(1001,atlas-pixie-dust-test-7-unsecure-1.openstacklocal,6667) with correlation id 0 for 1 topic(s) Set(ATLAS_HOOK) (ClientUtils$:68) > 2016-09-01 10:46:42,098 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Connected to atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667 for producing (SyncProducer:68) > 2016-09-01 10:46:42,135 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ Disconnecting from atlas-pixie-dust-test-7-unsecure-1.openstacklocal:6667 (SyncProducer:68) > 2016-09-01 10:46:42,145 INFO - [main:] ~ Refreshing Root WebApplicationContext: startup date [Thu Sep 01 10:46:42 UTC 2016]; root of context hierarchy (XmlWebApplicationContext:503) > 2016-09-01 10:46:42,181 INFO - [ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002:] ~ [ConsumerFetcherThread-atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-0-1002], Starting (ConsumerFetcherThread:68) > 2016-09-01 10:46:42,190 INFO - [atlas_atlas-pixie-dust-test-7-unsecure-1-1472726801437-dc09262c-leader-finder-thread:] ~ [ConsumerFetcherManager-1472726801467] Added fetcher for partitions ArrayBuffer([[ATLAS_HOOK,0], initOffset 3 to broker BrokerEndPoint(1002,atlas-pixie-dust-test-7-unsecure-3.openstacklocal,6667)] ) (ConsumerFetcherManager:68) > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)