You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@atlas.apache.org by "Ayub Khan (JIRA)" <ji...@apache.org> on 2016/09/01 11:07:20 UTC

[jira] [Created] (ATLAS-1153) When ATLAS_HOOK topic is not created by Atlas, it is not reading messages from the beginning

Ayub Khan created ATLAS-1153:
--------------------------------

             Summary: 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)